misc: improve client app logging

- introduce a message handler
- introduce a logging category for the mainapplication object
- demo the filtering

Gitlab: #652
Change-Id: Ice1ea380bb330f576a0936e3048eb4c60a06d4e9

src/app/main.cpp

@@ -21,9 +21,12 @@
 #include "mainapplication.h"
 #include "instancemanager.h"
 #include "version.h"
+#if defined(Q_OS_MACOS)
+#include <os/macos/macutils.h>
+#endif
 
-#include <QCryptographicHash>
 #include <QApplication>
+#include <QCryptographicHash>
 #include <QtQuick>
 #ifdef WITH_WEBENGINE
 #include <QtWebEngineCore>
@@ -32,14 +35,10 @@
 #if defined(HAS_VULKAN) && !defined(Q_OS_LINUX)
 #include <QVulkanInstance>
 #endif
-#if defined(Q_OS_MACOS)
-#include <os/macos/macutils.h>
-#endif
 
 #include <clocale>
 
 #ifndef ENABLE_TESTS
-
 int
 main(int argc, char* argv[])
 {

src/app/mainapplication.cpp

@@ -38,6 +38,7 @@
 #include <QTranslator>
 #include <QLibraryInfo>
 #include <QQuickWindow>
+#include <QLoggingCategory>
 
 #include <locale.h>
 #include <thread>
@@ -51,6 +52,37 @@
 #include "dbuserrorhandler.h"
 #endif
 
+Q_LOGGING_CATEGORY(app_, "app_")
+
+static const QtMessageHandler QT_DEFAULT_MESSAGE_HANDLER = qInstallMessageHandler(0);
+
+void
+messageHandler(QtMsgType type, const QMessageLogContext& context, const QString& msg)
+{
+    const static std::string fmt[5] = {"DBG", "WRN", "CRT", "FTL", "INF"};
+    const QByteArray localMsg = msg.toUtf8();
+    const auto ts = QString::number(QDateTime::currentMSecsSinceEpoch());
+
+    QString fileLineInfo = "";
+#ifdef QT_DEBUG
+    // In debug mode, always include file and line info.
+    fileLineInfo = QString("[%1:%2]").arg(context.file ? context.file : "unknown",
+                                          context.line ? QString::number(context.line) : "0");
+#else
+    // In release mode, include file and line info only for QML category which will always
+    // be available and provide a link to the source code in QtCreator.
+    if (QString(context.category) == QLatin1String("qml")) {
+        fileLineInfo = QString("[%1:%2]").arg(context.file ? context.file : "unknown",
+                                              context.line ? QString::number(context.line) : "0");
+    }
+#endif
+
+    const auto fmtMsg = QString("[%1][%2]%3: %4")
+                            .arg(ts, fmt[type].c_str(), fileLineInfo, localMsg.constData());
+
+    (*QT_DEFAULT_MESSAGE_HANDLER)(type, context, fmtMsg);
+}
+
 static QString
 getRenderInterfaceString()
 {
@@ -109,13 +141,34 @@ MainApplication::MainApplication(int& argc, char** argv)
     , isCleanupped(false)
 {
     const char* qtVersion = qVersion();
-    qInfo() << "Using Qt runtime version:" << qtVersion;
     if (strncmp(qtVersion, QT_VERSION_STR, strnlen(qtVersion, sizeof qtVersion)) != 0) {
-        qFatal("Qt build version mismatch! %s", QT_VERSION_STR);
+        qCFatal(app_) << "Qt build version mismatch!" << QT_VERSION_STR;
     }
 
     parseArguments();
+
+    // Adjust the log levels as needed (as logging categories are added).
+    // Note: the following will cause detailed Qt logging and effectively spam the console
+    // without using `qt.*=false`. It may be useful for debugging Qt/QtQuick issues.
+    QLoggingCategory::setFilterRules("\n"
+                                     "*.debug=true\n"
+                                     "qt.*=false\n"
+                                     "qml.debug=false\n"
+                                     "\n");
+    // These can be set in the environment as well.
+    // e.g. QT_LOGGING_RULES="*.debug=false;qml.debug=true"
+
+    // Tab align the log messages.
+    qSetMessagePattern("%{category}\t%{message}");
+
+    // Registration is done late here contrary to suggested practice in order to
+    // allow for the arguments to be parsed first in case we want to influence
+    // the logging features.
+    qInstallMessageHandler(messageHandler);
+
     QObject::connect(this, &QApplication::aboutToQuit, this, &MainApplication::cleanup);
+
+    qCInfo(app_) << "Using Qt runtime version:" << qtVersion;
 }
 
 MainApplication::~MainApplication()
@@ -235,10 +288,10 @@ MainApplication::handleUriAction(const QString& arg)
     QString uri {};
     if (arg.isEmpty() && !runOptions_[Option::StartUri].isNull()) {
         uri = runOptions_[Option::StartUri].toString();
-        qDebug() << "URI action invoked by run option" << uri;
+        qCDebug(app_) << "URI action invoked by run option" << uri;
     } else if (!arg.isEmpty()) {
         uri = arg;
-        qDebug() << "URI action invoked by secondary instance" << uri;
+        qCDebug(app_) << "URI action invoked by secondary instance" << uri;
         Q_EMIT searchAndSelect(uri.replace("jami:", ""));
     }
 }
@@ -360,7 +413,7 @@ MainApplication::initQmlLayer()
     engine_->rootContext()->setContextProperty("videoProvider", videoProvider);
 
     engine_->load(QUrl(QStringLiteral("qrc:/MainApplicationWindow.qml")));
-    qWarning().noquote() << "Main window loaded using" << getRenderInterfaceString();
+    qCWarning(app_) << "Main window loaded using" << getRenderInterfaceString();
 }
 
 void

src/app/mainview/components/ChatView.qml

@@ -214,7 +214,7 @@ Rectangle {
             onExtrasPanelWidthChanged: {
                 resolvePanes();
                 // This range should ensure that the panel won't restore to maximized.
-                if (extrasPanelWidth != 0 && extrasPanelWidth != width) {
+                if (extrasPanelWidth !== 0 && extrasPanelWidth !== width) {
                     console.debug("Saving previous extras panel width: %1".arg(extrasPanelWidth));
                     previousExtrasPanelWidth = extrasPanelWidth;
                 }