Merge pull request #2145 from nextcloud/repair_and_improve_logging

Repair and improve logging

src/csync/csync.cpp

@@ -49,7 +49,7 @@
 #include "common/c_jhash.h"
 #include "common/syncjournalfilerecord.h"
 
-Q_LOGGING_CATEGORY(lcCSync, "sync.csync.csync", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcCSync, "nextcloud.sync.csync.csync", QtInfoMsg)
 
 
 csync_s::csync_s(const char *localUri, OCC::SyncJournalDb *statedb)

src/csync/csync_util.cpp

@@ -34,7 +34,7 @@
 #include "csync_util.h"
 #include "vio/csync_vio.h"
 
-Q_LOGGING_CATEGORY(lcCSyncUtils, "sync.csync.utils", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcCSyncUtils, "nextcloud.sync.csync.utils", QtInfoMsg)
 
 
 typedef struct {

src/csync/vio/csync_vio_local_unix.cpp

@@ -37,7 +37,7 @@
 
 #include "vio/csync_vio_local.h"
 
-Q_LOGGING_CATEGORY(lcCSyncVIOLocal, "sync.csync.vio_local", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcCSyncVIOLocal, "nextcloud.sync.csync.vio_local", QtInfoMsg)
 
 /*
  * directory functions

src/csync/vio/csync_vio_local_win.cpp

@@ -37,7 +37,7 @@
 
 #include "vio/csync_vio_local.h"
 
-Q_LOGGING_CATEGORY(lcCSyncVIOLocal, "sync.csync.vio_local", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcCSyncVIOLocal, "nextcloud.sync.csync.vio_local", QtInfoMsg)
 
 /*
  * directory functions

src/gui/application.cpp

@@ -408,10 +408,10 @@ void Application::setupLogging()
     // might be called from second instance
     auto logger = Logger::instance();
     logger->setLogFile(_logFile);
-    logger->setLogDir(_logDir);
-    logger->setLogExpire(_logExpire);
-    logger->setLogFlush(_logFlush);
-    logger->setLogDebug(_logDebug);
+    logger->setLogDir(!_logDir.isEmpty() ? _logDir : ConfigFile().logDir());
+    logger->setLogExpire(_logExpire > 0 ? _logExpire : ConfigFile().logExpire());
+    logger->setLogFlush(_logFlush || ConfigFile().logFlush());
+    logger->setLogDebug(_logDebug || ConfigFile().logDebug());
     if (!logger->isLoggingToFile() && ConfigFile().automaticLogDir()) {
         logger->setupTemporaryFolderLogDir();
     }

src/gui/creds/webflowcredentials.cpp

@@ -24,7 +24,7 @@ using namespace QKeychain;
 
 namespace OCC {
 
-Q_LOGGING_CATEGORY(lcWebFlowCredentials, "sync.credentials.webflow", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcWebFlowCredentials, "nextcloud.sync.credentials.webflow", QtInfoMsg)
 
 namespace {
     const char userC[] = "user";

src/gui/socketapi.cpp

@@ -87,8 +87,8 @@ static QString buildMessage(const QString &verb, const QString &path, const QStr
 
 namespace OCC {
 
-Q_LOGGING_CATEGORY(lcSocketApi, "gui.socketapi", QtInfoMsg)
-Q_LOGGING_CATEGORY(lcPublicLink, "gui.socketapi.publiclink", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcSocketApi, "nextcloud.gui.socketapi", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcPublicLink, "nextcloud.gui.socketapi.publiclink", QtInfoMsg)
 
 
 class BloomFilter

src/gui/wizard/flow2authwidget.cpp

@@ -22,7 +22,7 @@
 
 namespace OCC {
 
-Q_LOGGING_CATEGORY(lcFlow2AuthWidget, "gui.wizard.flow2authwidget", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcFlow2AuthWidget, "nextcloud.gui.wizard.flow2authwidget", QtInfoMsg)
 
 
 Flow2AuthWidget::Flow2AuthWidget(QWidget *parent)

src/gui/wizard/webview.cpp

@@ -20,7 +20,7 @@
 
 namespace OCC {
 
-Q_LOGGING_CATEGORY(lcWizardWebiew, "gui.wizard.webview", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcWizardWebiew, "nextcloud.gui.wizard.webview", QtInfoMsg)
 
 
 class WebViewPageUrlRequestInterceptor : public QWebEngineUrlRequestInterceptor

src/gui/wizard/webviewpage.cpp

@@ -12,7 +12,7 @@
 
 namespace OCC {
 
-Q_LOGGING_CATEGORY(lcWizardWebiewPage, "gui.wizard.webviewpage", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcWizardWebiewPage, "nextcloud.gui.wizard.webviewpage", QtInfoMsg)
 
 
 WebViewPage::WebViewPage(QWidget *parent)

src/libsync/configfile.cpp

@@ -50,7 +50,7 @@ namespace OCC {
 
 namespace chrono = std::chrono;
 
-Q_LOGGING_CATEGORY(lcConfigFile, "sync.configfile", QtInfoMsg)
+Q_LOGGING_CATEGORY(lcConfigFile, "nextcloud.sync.configfile", QtInfoMsg)
 
 //static const char caCertsKeyC[] = "CaCertificates"; only used from account.cpp
 static const char remotePollIntervalC[] = "remotePollInterval";
@@ -73,6 +73,10 @@ static const char minChunkSizeC[] = "minChunkSize";
 static const char maxChunkSizeC[] = "maxChunkSize";
 static const char targetChunkUploadDurationC[] = "targetChunkUploadDuration";
 static const char automaticLogDirC[] = "logToTemporaryLogDir";
+static const char logDirC[] = "logDir";
+static const char logDebugC[] = "logDebug";
+static const char logExpireC[] = "logExpire";
+static const char logFlushC[] = "logFlush";
 
 static const char proxyHostC[] = "Proxy/host";
 static const char proxyTypeC[] = "Proxy/type";
@@ -853,6 +857,54 @@ void ConfigFile::setAutomaticLogDir(bool enabled)
     settings.setValue(QLatin1String(automaticLogDirC), enabled);
 }
 
+QString ConfigFile::logDir() const
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    return settings.value(QLatin1String(logDirC), QString()).toString();
+}
+
+void ConfigFile::setLogDir(const QString &dir)
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    settings.setValue(QLatin1String(logDirC), dir);
+}
+
+bool ConfigFile::logDebug() const
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    return settings.value(QLatin1String(logDebugC), false).toBool();
+}
+
+void ConfigFile::setLogDebug(bool enabled)
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    settings.setValue(QLatin1String(logDebugC), enabled);
+}
+
+int ConfigFile::logExpire() const
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    return settings.value(QLatin1String(logExpireC), 0).toBool();
+}
+
+void ConfigFile::setLogExpire(int hours)
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    settings.setValue(QLatin1String(logExpireC), hours);
+}
+
+bool ConfigFile::logFlush() const
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    return settings.value(QLatin1String(logFlushC), false).toBool();
+}
+
+void ConfigFile::setLogFlush(bool enabled)
+{
+    QSettings settings(configFile(), QSettings::IniFormat);
+    settings.setValue(QLatin1String(logFlushC), enabled);
+}
+
 QString ConfigFile::certificatePath() const
 {
     return retrieveData(QString(), QLatin1String(certPath)).toString();

src/libsync/configfile.h

@@ -92,6 +92,18 @@ public:
     bool automaticLogDir() const;
     void setAutomaticLogDir(bool enabled);
 
+    QString logDir() const;
+    void setLogDir(const QString &dir);
+
+    bool logDebug() const;
+    void setLogDebug(bool enabled);
+
+    int logExpire() const;
+    void setLogExpire(int hours);
+
+    bool logFlush() const;
+    void setLogFlush(bool enabled);
+
     // proxy settings
     void setProxyType(int proxyType,
         const QString &host = QString(),

src/libsync/logger.cpp

@@ -18,11 +18,17 @@
 
 #include <QDir>
 #include <QStringList>
-#include <QThread>
+#include <QtGlobal>
 #include <qmetaobject.h>
 
+#include <iostream>
+
 #include <zlib.h>
 
+#ifdef Q_OS_WIN
+#include <io.h> // for stdout
+#endif
+
 namespace OCC {
 
 QtMessageHandler s_originalMessageHandler = nullptr;
@@ -37,6 +43,19 @@ static void mirallLogCatcher(QtMsgType type, const QMessageLogContext &ctx, cons
     } else if (!logger->isNoop()) {
         logger->doLog(qFormatLogMessage(type, ctx, message));
     }
+    if(type == QtCriticalMsg || type == QtFatalMsg) {
+        std::cerr << qPrintable(qFormatLogMessage(type, ctx, message)) << std::endl;
+    }
+
+    if(type == QtFatalMsg) {
+        if (!logger->isNoop()) {
+            logger->close();
+        }
+#if defined(Q_OS_WIN)
+    // Make application terminate in a way that can be caught by the crash reporter
+        Utility::crash();
+#endif
+    }
 }
 
 
@@ -49,7 +68,7 @@ Logger *Logger::instance()
 Logger::Logger(QObject *parent)
     : QObject(parent)
 {
-    qSetMessagePattern("[%{function} \t%{message}");
+    qSetMessagePattern("%{time yyyy-MM-dd hh:mm:ss:zzz} [ %{type} %{category} ]%{if-debug}\t[ %{function} ]%{endif}:\t%{message}");
 #ifndef NO_MSG_HANDLER
    s_originalMessageHandler = qInstallMessageHandler(mirallLogCatcher);
 #else
@@ -87,7 +106,6 @@ void Logger::log(Log log)
         msg = log.timeStamp.toString(QLatin1String("MM-dd hh:mm:ss:zzz")) + QLatin1Char(' ');
     }
 
-    msg += QString().sprintf("%p ", (void *)QThread::currentThread());
     msg += log.message;
     // _logs.append(log);
     // std::cout << qPrintable(log.message) << std::endl;
@@ -123,6 +141,17 @@ void Logger::doLog(const QString &msg)
     emit logWindowLog(msg);
 }
 
+void Logger::close()
+{
+    QMutexLocker lock(&_mutex);
+    if (_logstream)
+    {
+        _logstream->flush();
+        _logFile.close();
+        _logstream.reset();
+    }
+}
+
 void Logger::mirallLog(const QString &message)
 {
     Log log_;
@@ -152,7 +181,7 @@ void Logger::setLogFile(const QString &name)
 
     bool openSucceeded = false;
     if (name == QLatin1String("-")) {
-        openSucceeded = _logFile.open(1, QIODevice::WriteOnly);
+        openSucceeded = _logFile.open(stdout, QIODevice::WriteOnly);
     } else {
         _logFile.setFileName(name);
         openSucceeded = _logFile.open(QIODevice::WriteOnly);
@@ -187,7 +216,7 @@ void Logger::setLogFlush(bool flush)
 
 void Logger::setLogDebug(bool debug)
 {
-    QLoggingCategory::setFilterRules(debug ? QStringLiteral("sync.*.debug=true\ngui.*.debug=true") : QString());
+    QLoggingCategory::setFilterRules(debug ? QStringLiteral("nextcloud.*.debug=true") : QString());
     _logDebug = debug;
 }
 
@@ -257,7 +286,7 @@ void Logger::enterNextLogFile()
 
         // Expire old log files and deal with conflicts
         QStringList files = dir.entryList(QStringList("*owncloud.log.*"),
-            QDir::Files);
+            QDir::Files, QDir::Name);
         QRegExp rx(R"(.*owncloud\.log\.(\d+).*)");
         int maxNumber = -1;
         foreach (const QString &s, files) {
@@ -276,10 +305,15 @@ void Logger::enterNextLogFile()
         auto previousLog = _logFile.fileName();
         setLogFile(dir.filePath(newLogName));
 
-        if (!previousLog.isEmpty()) {
-            QString compressedName = previousLog + ".gz";
-            if (compressLog(previousLog, compressedName)) {
-                QFile::remove(previousLog);
+        // Compress the previous log file. On a restart this can be the most recent
+        // log file.
+        auto logToCompress = previousLog;
+        if (logToCompress.isEmpty() && files.size() > 0 && !files.last().endsWith(".gz"))
+            logToCompress = dir.absoluteFilePath(files.last());
+        if (!logToCompress.isEmpty()) {
+            QString compressedName = logToCompress + ".gz";
+            if (compressLog(logToCompress, compressedName)) {
+                QFile::remove(logToCompress);
             } else {
                 QFile::remove(compressedName);
             }

src/libsync/logger.h

@@ -47,6 +47,7 @@ public:
 
     void log(Log log);
     void doLog(const QString &log);
+    void close();
 
     static void mirallLog(const QString &message);