Logging cleanup and add options to force long console log format

cmake/MythOptions.cmake

@@ -166,6 +166,10 @@ option(
   ENABLE_EXIV2_DOWNLOAD
   "Build latest exiv2 instead of embedded copy.  This only afects native builds. Android/Windows builds will always downloded exiv2."
   OFF)
+option(
+  CONFIG_FORCE_LOGLONG
+  "Use long loging format for the console (i.e. show file, line number, etc.)."
+  OFF)
 
 #
 # Miscellaneous compilation options

mythtv/configure

@@ -1921,6 +1921,7 @@ MYTHTV_CONFIG_LIST='
     systemd_notify
     systemd_journal
     drm
+    force_loglong
 '
 
 MYTHTV_HAVE_LIST='

mythtv/libs/libmythbase/logging.cpp

@@ -76,9 +76,10 @@ struct LogPropagateOpts {
     int     m_quiet;
     int     m_facility;
     QString m_path;
+    bool    m_loglong;
 };
 
-LogPropagateOpts        logPropagateOpts {false, 0, 0, ""};
+LogPropagateOpts        logPropagateOpts {false, 0, 0, "", false};
 QString                 logPropagateArgs;
 QStringList             logPropagateArgList;
 
@@ -212,15 +213,44 @@ char LoggingItem::getLevelChar (void)
     return '-';
 }
 
+std::string LoggingItem::toString()
+{
+    QString ptid = QString::number(pid()); // pid, add tid if non-zero
+    if(tid())
+    {
+        ptid.append("/").append(QString::number(tid()));
+    }
+    return qPrintable(QString("%1 %2 [%3] %4 %5:%6:%7  %8\n")
+                          .arg(getTimestampUs(),
+                               QString(QChar(getLevelChar())),
+                               ptid,
+                               threadName(),
+                               file(),
+                               QString::number(line()),
+                               function(),
+                               message()
+                              ));
+}
+
+std::string LoggingItem::toStringShort()
+{
+    return qPrintable(QString("%1 %2  %3\n")
+                          .arg(getTimestampUs(),
+                               QString(QChar(getLevelChar())),
+                               message()
+                              ));
+}
+
 /// \brief LoggerThread constructor.  Enables debugging of thread registration
 ///        and deregistration if the VERBOSE_THREADS environment variable is
 ///        set.
 LoggerThread::LoggerThread(QString filename, bool progress, bool quiet,
-                           int facility) :
+                           int facility, bool loglong) :
     MThread("Logger"),
     m_waitNotEmpty(new QWaitCondition()),
     m_waitEmpty(new QWaitCondition()),
     m_filename(std::move(filename)), m_progress(progress), m_quiet(quiet),
+    m_loglong(loglong),
     m_facility(facility), m_pid(getpid())
 {
     if (qEnvironmentVariableIsSet("VERBOSE_THREADS"))
@@ -380,41 +410,21 @@ bool LoggerThread::logConsole(LoggingItem *item) const
     }
     else
     {
-        QString timestamp = item->getTimestampUs();
-        char shortname = item->getLevelChar();
-
-#ifndef NDEBUG
-        if (item->tid())
+#if !defined(NDEBUG) || CONFIG_FORCE_LOGLONG
+        if (true)
+#else
+        if (m_loglong)
+#endif
         {
-            line = qPrintable(QString("%1 %2 [%3/%4] %5 %6:%7:%8  %9\n")
-                .arg(timestamp, QString(shortname),
-                     QString::number(item->pid()),
-                     QString::number(item->tid()),
-                     item->threadName(),
-                     item->m_file,
-                     QString::number(item->m_line),
-                     item->m_function,
-                     item->m_message));
+            line = item->toString();
         }
         else
         {
-            line = qPrintable(QString("%1 %2 [%3] %4 %5:%6:%7  %8\n")
-                .arg(timestamp, QString(shortname),
-                     QString::number(item->pid()),
-                     item->threadName(),
-                     item->m_file,
-                     QString::number(item->m_line),
-                     item->m_function,
-                     item->m_message));
+            line = item->toStringShort();
         }
-#else
-        line = qPrintable(QString("%1 %2  %3\n")
-                          .arg(timestamp, QString(shortname),
-                               item->m_message));
-#endif
     }
 
-    (void)write(1, line.data(), line.size());
+    std::cout << line;
 
 #else // Q_OS_ANDROID
 
@@ -593,6 +603,12 @@ void logPropagateCalc(void)
         logPropagateArgList << "--quiet";
     }
 
+    if (logPropagateOpts.m_loglong)
+    {
+        logPropagateArgs += " --loglong";
+        logPropagateArgList << "--loglong";
+    }
+
 #if !defined(_WIN32) && !defined(Q_OS_ANDROID)
     if (logPropagateOpts.m_facility >= 0)
     {
@@ -635,7 +651,7 @@ bool logPropagateQuiet(void)
 /// \param  testHarness Should always be false. Set to true when
 ///                     invoked by the testing code.
 void logStart(const QString& logfile, bool progress, int quiet, int facility,
-              LogLevel_t level, bool propagate, bool testHarness)
+              LogLevel_t level, bool propagate, bool loglong, bool testHarness)
 {
     if (logThread && logThread->isRunning())
         return;
@@ -647,6 +663,7 @@ void logStart(const QString& logfile, bool progress, int quiet, int facility,
     logPropagateOpts.m_propagate = propagate;
     logPropagateOpts.m_quiet = quiet;
     logPropagateOpts.m_facility = facility;
+    logPropagateOpts.m_loglong = loglong;
 
     if (propagate)
     {
@@ -660,7 +677,7 @@ void logStart(const QString& logfile, bool progress, int quiet, int facility,
         return;
 
     if (!logThread)
-        logThread = new LoggerThread(logfile, progress, quiet, facility);
+        logThread = new LoggerThread(logfile, progress, quiet, facility, loglong);
 
     logThread->start();
 }

mythtv/libs/libmythbase/logging.h

@@ -9,6 +9,7 @@
 
 #include <cstdint>
 #include <cstdlib>
+#include <string>
 
 #include "mythconfig.h"
 #include "mythbaseexp.h"  //  MBASE_PUBLIC , etc.
@@ -115,6 +116,9 @@ class LoggingItem: public QObject, public ReferenceCounter
     void setLogFile(const QString &val)     { m_logFile = val; };
     void setMessage(const QString &val)     { m_message = val; };
 
+    std::string toString(); ///< @brief Long format to string
+    std::string toStringShort(); ///< @brief short console format
+
   protected:
     int                 m_pid        {-1};
     qlonglong           m_tid        {-1};
@@ -148,7 +152,7 @@ class LoggerThread : public QObject, public MThread
     friend MBASE_PUBLIC void LogPrintLine(uint64_t mask, LogLevel_t level, const char *file, int line,
                              const char *function, QString message);
   public:
-    LoggerThread(QString filename, bool progress, bool quiet, int facility);
+    LoggerThread(QString filename, bool progress, bool quiet, int facility, bool loglong);
     ~LoggerThread() override;
     void run(void) override; // MThread
     void stop(void);
@@ -170,6 +174,7 @@ class LoggerThread : public QObject, public MThread
     QString m_filename;    ///< Filename of debug logfile
     bool    m_progress;    ///< show only LOG_ERR and more important (console only)
     bool    m_quiet;       ///< silence the console (console only)
+    bool    m_loglong;     ///< use long log format (console only)
     QString m_appname {QCoreApplication::applicationName()};
                            ///< Cached application name
     int     m_facility;    ///< Cached syslog facility (or -1 to disable)

mythtv/libs/libmythbase/loggingserver.cpp

@@ -1,3 +1,5 @@
+#include <fstream>
+
 #include <QtGlobal>
 #include <QAtomicInt>
 #include <QMutex>
@@ -105,9 +107,8 @@ LoggerBase::~LoggerBase()
 /// \param filename Filename of the logfile.
 FileLogger::FileLogger(const char *filename) :
         LoggerBase(filename),
-        m_fd(open(filename, O_WRONLY|O_CREAT|O_APPEND, 0664))
+        m_ofstream(filename, std::ios::app)
 {
-    m_opened = (m_fd != -1);
     LOG(VB_GENERAL, LOG_INFO, QString("Added logging to %1")
              .arg(filename));
 }
@@ -116,13 +117,11 @@ FileLogger::FileLogger(const char *filename) :
 /// \brief FileLogger deconstructor - close the logfile
 FileLogger::~FileLogger()
 {
-    if( m_opened )
+    if(m_ofstream.is_open())
     {
         LOG(VB_GENERAL, LOG_INFO, QString("Removed logging to %1")
             .arg(m_handle));
-        close(m_fd);
-        m_fd = -1;
-        m_opened = false;
+        m_ofstream.close();
     }
 }
 
@@ -131,7 +130,7 @@ FileLogger *FileLogger::create(const QString& filename, QMutex *mutex)
     QByteArray ba = filename.toLocal8Bit();
     const char *file = ba.constData();
     auto *logger =
-        qobject_cast<FileLogger *>(loggerMap.value(filename, nullptr));
+        dynamic_cast<FileLogger *>(loggerMap.value(filename, nullptr));
 
     if (logger)
         return logger;
@@ -149,54 +148,28 @@ FileLogger *FileLogger::create(const QString& filename, QMutex *mutex)
 ///        This allows for logrollers to be used.
 void FileLogger::reopen(void)
 {
-    close(m_fd);
+    m_ofstream.close();
 
-    m_fd = open(qPrintable(m_handle), O_WRONLY|O_CREAT|O_APPEND, 0664);
-    m_opened = (m_fd != -1);
+    m_ofstream.open(qPrintable(m_handle), std::ios::app);
     LOG(VB_GENERAL, LOG_INFO, QString("Rolled logging on %1") .arg(m_handle));
 }
 
 /// \brief Process a log message, writing to the logfile
 /// \param item LoggingItem containing the log message to process
 bool FileLogger::logmsg(LoggingItem *item)
 {
-    if (!m_opened)
+    if (!m_ofstream.is_open())
         return false;
 
-    QString timestamp = item->getTimestampUs();
-    QChar shortname = item->getLevelChar();
-
-    std::string line;
-    if( item->tid() )
-    {
-        line = qPrintable(QString("%1 %2 [%3/%4] %5 %6:%7 (%8) - %9\n")
-                          .arg(timestamp, shortname,
-                               QString::number(item->pid()),
-                               QString::number(item->tid()),
-                               item->threadName(), item->file(),
-                               QString::number(item->line()),
-                               item->function(),
-                               item->message()));
-    }
-    else
-    {
-        line = qPrintable(QString("%1 %2 [%3] %5 %6:%7 (%8) - %9\n")
-                          .arg(timestamp, shortname,
-                               QString::number(item->pid()),
-                               item->threadName(), item->file(),
-                               QString::number(item->line()),
-                               item->function(),
-                               item->message()));
-    }
+    std::string line = item->toString();
 
-    int result = write(m_fd, line.data(), line.size());
+    m_ofstream << line;
 
-    if( result == -1 )
+    if (m_ofstream.bad())
     {
         LOG(VB_GENERAL, LOG_ERR,
-                 QString("Closed Log output on fd %1 due to errors").arg(m_fd));
-        m_opened = false;
-        close( m_fd );
+            QString("Closed Log output to %1 due to unrecoverable error(s).").arg(m_handle));
+        m_ofstream.close();
         return false;
     }
     return true;
@@ -227,7 +200,7 @@ SyslogLogger::~SyslogLogger()
 
 SyslogLogger *SyslogLogger::create(QMutex *mutex, bool open)
 {
-    auto *logger = qobject_cast<SyslogLogger *>(loggerMap.value("", nullptr));
+    auto *logger = dynamic_cast<SyslogLogger *>(loggerMap.value("", nullptr));
     if (logger)
         return logger;
 
@@ -273,7 +246,7 @@ JournalLogger::~JournalLogger()
 
 JournalLogger *JournalLogger::create(QMutex *mutex)
 {
-    auto *logger = qobject_cast<JournalLogger *>(loggerMap.value("", nullptr));
+    auto *logger = dynamic_cast<JournalLogger *>(loggerMap.value("", nullptr));
     if (logger)
         return logger;
 

mythtv/libs/libmythbase/loggingserver.h

@@ -9,6 +9,7 @@
 
 #include <cstdint>
 #include <ctime>
+#include <fstream>
 #include <unistd.h>
 
 #include "mythconfig.h"
@@ -21,15 +22,13 @@ class MSqlQuery;
 class LoggingItem;
 
 /// \brief Base class for the various logging mechanisms
-class LoggerBase : public QObject
+class LoggerBase
 {
-    Q_OBJECT
-
   public:
     /// \brief LoggerBase Constructor
     explicit LoggerBase(const char *string);
     /// \brief LoggerBase Deconstructor
-    ~LoggerBase() override;
+    virtual ~LoggerBase();
     /// \brief Process a log message for the logger instance
     /// \param item LoggingItem containing the log message to process
     virtual bool logmsg(LoggingItem *item) = 0;
@@ -42,25 +41,20 @@ class LoggerBase : public QObject
 /// \brief File-based logger - used for logfiles and console
 class FileLogger : public LoggerBase
 {
-    Q_OBJECT
-
   public:
     explicit FileLogger(const char *filename);
     ~FileLogger() override;
     bool logmsg(LoggingItem *item) override; // LoggerBase
     void reopen(void) override; // LoggerBase
     static FileLogger *create(const QString& filename, QMutex *mutex);
   private:
-    bool m_opened {false}; ///< true when the logfile is opened
-    int  m_fd     {-1};    ///< contains the file descriptor for the logfile
+    std::ofstream m_ofstream; ///< Output file stream for the log file.
 };
 
 #ifndef _WIN32
 /// \brief Syslog-based logger (not available in Windows)
 class SyslogLogger : public LoggerBase
 {
-    Q_OBJECT
-
   public:
     explicit SyslogLogger(bool open);
     ~SyslogLogger() override;
@@ -76,8 +70,6 @@ class SyslogLogger : public LoggerBase
 #if CONFIG_SYSTEMD_JOURNAL
 class JournalLogger : public LoggerBase
 {
-    Q_OBJECT
-
   public:
     JournalLogger();
     ~JournalLogger() override;