misc: improve logging for the client and libclient projects

- Declares global logging categories for libclient and the app
- Introduces some macros for categorized logging
- Removes the noisy namedirectory logs by default
- Logs file/line number URIs in debug mode

Change-Id: I9dadadc6e93ef91cc70d206b7225aeb7a06f8773

CMakeLists.txt

@@ -303,6 +303,7 @@ set(COMMON_SOURCES
   ${APP_SRC_DIR}/pluginversionmanager.cpp)
 
 set(COMMON_HEADERS
+  ${APP_SRC_DIR}/global.h
   ${APP_SRC_DIR}/avatarimageprovider.h
   ${APP_SRC_DIR}/networkmanager.h
   ${APP_SRC_DIR}/smartlistmodel.h

src/app/global.h

@@ -0,0 +1,27 @@
+/*
+ * Copyright (C) 2024 Savoir-faire Linux Inc.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ */
+
+#pragma once
+
+#include <QtCore/QLoggingCategory>
+
+Q_DECLARE_LOGGING_CATEGORY(clientLog)
+#define C_DBG   qCDebug(clientLog)
+#define C_INFO  qCInfo(clientLog)
+#define C_WARN  qCWarning(clientLog)
+#define C_ERR   qCCritical(clientLog)
+#define C_FATAL qCFatal(clientLog)

src/app/mainapplication.cpp

@@ -21,6 +21,7 @@
 
 #include "mainapplication.h"
 
+#include "global.h"
 #include "qmlregister.h"
 #include "appsettingsmanager.h"
 #include "connectivitymonitor.h"
@@ -40,7 +41,6 @@
 #include <QTranslator>
 #include <QLibraryInfo>
 #include <QQuickWindow>
-#include <QLoggingCategory>
 
 #include <thread>
 
@@ -53,7 +53,7 @@
 #include "dbuserrorhandler.h"
 #endif
 
-Q_LOGGING_CATEGORY(app_, "app_")
+Q_LOGGING_CATEGORY(clientLog, "client")
 
 static const QtMessageHandler QT_DEFAULT_MESSAGE_HANDLER = qInstallMessageHandler(0);
 
@@ -65,20 +65,26 @@ messageHandler(QtMsgType type, const QMessageLogContext& context, const QString&
     const auto ts = QString::number(QDateTime::currentMSecsSinceEpoch());
 
     QString fileLineInfo = "";
+    const auto isQml = QString(context.category) == QLatin1String("qml");
 #ifdef QT_DEBUG
-    // In debug mode, always include file and line info.
+    // In debug mode, always include file URI (including line info).
-    fileLineInfo = QString("[%1:%2]").arg(context.file ? context.file : "unknown",
+    // Only do this when the level Info/Debug, as it is already included in the constructed
+    // message for the other levels.
+    if (type == QtDebugMsg || type == QtInfoMsg) {
+        auto fileName = isQml ? context.file : QUrl::fromLocalFile(context.file).toString();
+        fileLineInfo = QString(" %1:%2").arg(!fileName.isEmpty() ? fileName : "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")) {
+    if (isQml) {
         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")
+    const auto fmtMsg = QString("[%1][%2]:%3 %4")
                             .arg(ts, fmt[type].c_str(), fileLineInfo, localMsg.constData());
 
     (*QT_DEFAULT_MESSAGE_HANDLER)(type, context, fmtMsg);
@@ -142,7 +148,7 @@ MainApplication::MainApplication(int& argc, char** argv)
 {
     const char* qtVersion = qVersion();
     if (strncmp(qtVersion, QT_VERSION_STR, strnlen(qtVersion, sizeof qtVersion)) != 0) {
-        qCFatal(app_) << "Qt build version mismatch!" << QT_VERSION_STR;
+        C_FATAL << "Qt build version mismatch!" << QT_VERSION_STR;
     }
 
     parseArguments();
@@ -152,6 +158,7 @@ MainApplication::MainApplication(int& argc, char** argv)
     // without using `qt.*=false`. It may be useful for debugging Qt/QtQuick issues.
     QLoggingCategory::setFilterRules("\n"
                                      "*.debug=true\n"
+                                     "libclient.debug=false\n"
                                      "qt.*=false\n"
                                      "qml.debug=false\n"
                                      "\n");
@@ -166,7 +173,7 @@ MainApplication::MainApplication(int& argc, char** argv)
     // the logging features.
     qInstallMessageHandler(messageHandler);
 
-    qCInfo(app_) << "Using Qt runtime version:" << qtVersion;
+    C_INFO << "Using Qt runtime version:" << qtVersion;
 }
 
 MainApplication::~MainApplication()
@@ -277,10 +284,10 @@ MainApplication::handleUriAction(const QString& arg)
     QString uri {};
     if (arg.isEmpty() && !runOptions_[Option::StartUri].isNull()) {
         uri = runOptions_[Option::StartUri].toString();
-        qCDebug(app_) << "URI action invoked by run option" << uri;
+        C_DBG << "URI action invoked by run option" << uri;
     } else if (!arg.isEmpty()) {
         uri = arg;
-        qCDebug(app_) << "URI action invoked by secondary instance" << uri;
+        C_DBG << "URI action invoked by secondary instance" << uri;
         Q_EMIT searchAndSelect(uri.replace("jami:", ""));
     }
 }
@@ -402,7 +409,7 @@ MainApplication::initQmlLayer()
     engine_->load(QUrl(QStringLiteral("qrc:/MainApplicationWindow.qml")));
 
     // Report the render interface used.
-    qCWarning(app_) << "Main window loaded using" << getRenderInterfaceString();
+    C_DBG << "Main window loaded using" << getRenderInterfaceString();
 }
 
 void

src/libclient/CMakeLists.txt

@@ -97,7 +97,9 @@ if (NOT (CMAKE_CXX_COMPILER_ID MATCHES "MSVC"))
     -Wno-reorder
     -Wunused
     -Woverloaded-virtual
-    -Wvarargs)
+    -Wvarargs
+    -Wno-gnu-zero-variadic-macro-arguments
+)
 endif()
 
 # Add more warnings for compilers that support it.

src/libclient/contactmodel.cpp

@@ -29,8 +29,6 @@
 #include "api/account.h"
 #include "api/contact.h"
 #include "api/conversationmodel.h"
-#include "api/interaction.h"
-#include "api/lrc.h"
 #include "api/accountmodel.h"
 #include "api/callmodel.h"
 #include "callbackshandler.h"
@@ -170,7 +168,11 @@ public Q_SLOTS:
      * @param isOutgoing
      * @param toUri
      */
-    void slotNewCall(const QString& fromId, const QString& callId, const QString& displayname, bool isOutgoing, const QString& toUri);
+    void slotNewCall(const QString& fromId,
+                     const QString& callId,
+                     const QString& displayname,
+                     bool isOutgoing,
+                     const QString& toUri);
 
     /**
      * Listen from callbacksHandler for new account interaction and add pending contact if not present
@@ -248,7 +250,7 @@ ContactModel::addContact(contact::Info contactInfo)
     // If passed contact is a banned contact, call the daemon to unban it
     auto it = std::find(pimpl_->bannedContacts.begin(), pimpl_->bannedContacts.end(), profile.uri);
     if (it != pimpl_->bannedContacts.end()) {
-        qDebug() << QString("Unban-ing contact %1").arg(profile.uri);
+        LC_DBG << QString("Unban-ing contact %1").arg(profile.uri);
         ConfigurationManager::instance().addContact(owner.id, profile.uri);
         // bannedContacts will be updated in slotContactAdded
         return;
@@ -256,7 +258,7 @@ ContactModel::addContact(contact::Info contactInfo)
 
     if ((owner.profileInfo.type != profile.type)
         and (profile.type == profile::Type::JAMI or profile.type == profile::Type::SIP)) {
-        qDebug() << "ContactModel::addContact, types invalid.";
+        LC_DBG << "ContactModel::addContact, types invalid.";
         return;
     }
 
@@ -292,7 +294,7 @@ ContactModel::addContact(contact::Info contactInfo)
     case profile::Type::INVALID:
     case profile::Type::COUNT__:
     default:
-        qDebug() << "ContactModel::addContact, cannot add contact with invalid type.";
+        LC_DBG << "ContactModel::addContact, cannot add contact with invalid type.";
         return;
     }
 
@@ -341,7 +343,7 @@ ContactModel::removeContact(const QString& contactUri, bool banned)
     try {
         const auto& contact = getContact(contactUri);
         if (contact.isBanned) {
-            qWarning() << "Contact already banned";
+            LC_WARN << "Contact already banned";
             return;
         }
     } catch (...) {
@@ -421,7 +423,7 @@ ContactModel::getSearchResults() const
 void
 ContactModel::searchContact(const QString& query)
 {
-    qDebug() << "query! " << query;
+    LC_DBG << "query! " << query;
     // always reset temporary contact
     pimpl_->searchResult.clear();
 
@@ -634,10 +636,7 @@ ContactModelPimpl::ContactModelPimpl(const ContactModel& linked,
             &CallbacksHandler::registeredNameFound,
             this,
             &ContactModelPimpl::slotRegisteredNameFound);
-    connect(&*linked.owner.callModel,
+    connect(&*linked.owner.callModel, &CallModel::newCall, this, &ContactModelPimpl::slotNewCall);
-            &CallModel::newCall,
-            this,
-            &ContactModelPimpl::slotNewCall);
     connect(&callbacksHandler,
             &lrc::CallbacksHandler::newAccountMessage,
             this,
@@ -674,10 +673,7 @@ ContactModelPimpl::~ContactModelPimpl()
                &CallbacksHandler::registeredNameFound,
                this,
                &ContactModelPimpl::slotRegisteredNameFound);
-    disconnect(&*linked.owner.callModel,
+    disconnect(&*linked.owner.callModel, &CallModel::newCall, this, &ContactModelPimpl::slotNewCall);
-               &CallModel::newCall,
-               this,
-               &ContactModelPimpl::slotNewCall);
     disconnect(&callbacksHandler,
                &lrc::CallbacksHandler::newAccountMessage,
                this,
@@ -910,8 +906,8 @@ ContactModelPimpl::slotContactRemoved(const QString& accountId,
                                     contact->profileInfo.uri);
                 if (it == bannedContacts.end()) {
                     // should not happen
-                    qDebug("ContactModel::slotContactsRemoved(): Contact is banned but not present "
+                    LC_DBG << "Contact is banned but not present in bannedContacts. This is most "
-                           "in bannedContacts. This is most likely the result of an earlier bug.");
+                              "likely the result of an earlier bug.";
                 } else {
                     bannedContacts.erase(it);
                 }

src/libclient/lrc.cpp

@@ -40,6 +40,8 @@
 #include "dbus/configurationmanager.h"
 #include "authority/storagehelper.h"
 
+Q_LOGGING_CATEGORY(libclientLog, "libclient")
+
 namespace lrc {
 
 using namespace api;

src/libclient/namedirectory.cpp

@@ -63,10 +63,11 @@ NameDirectoryPrivate::slotNameRegistrationEnded(const QString& accountId,
                                                 int status,
                                                 const QString& name)
 {
-    qDebug() << "Name registration ended. Account:" << accountId << "status:" << status
+    LC_DBG << "Name registration ended. Account:" << accountId << "status:" << status
            << "name:" << name;
 
-    Q_EMIT q_ptr->nameRegistrationEnded(static_cast<NameDirectory::RegisterNameStatus>(status), name);
+    Q_EMIT q_ptr->nameRegistrationEnded(static_cast<NameDirectory::RegisterNameStatus>(status),
+                                        name);
 }
 
 // Registered Name found
@@ -78,26 +79,31 @@ NameDirectoryPrivate::slotRegisteredNameFound(const QString& accountId,
 {
     switch (static_cast<NameDirectory::LookupStatus>(status)) {
     case NameDirectory::LookupStatus::INVALID_NAME:
-        qDebug() << "lookup name is INVALID: address: " << address << " name: " << name << " accountId: " << accountId;
+        LC_DBG << "lookup name is INVALID: address: " << address << " name: " << name
+               << " accountId: " << accountId;
         break;
     case NameDirectory::LookupStatus::NOT_FOUND:
-        qDebug() << "lookup name NOT FOUND: address: " << address << " name: " << name << " accountId: " << accountId;
+        LC_DBG << "lookup name NOT FOUND: address: " << address << " name: " << name
+               << " accountId: " << accountId;
         break;
     case NameDirectory::LookupStatus::ERROR:
-        qDebug() << "lookup name ERROR: address: " << address << " name: " << name << " accountId: " << accountId;
+        LC_DBG << "lookup name ERROR: address: " << address << " name: " << name
+               << " accountId: " << accountId;
         break;
     case NameDirectory::LookupStatus::SUCCESS:
         break;
     }
 
-    Q_EMIT q_ptr->registeredNameFound(static_cast<NameDirectory::LookupStatus>(status), address, name);
+    Q_EMIT q_ptr->registeredNameFound(static_cast<NameDirectory::LookupStatus>(status),
+                                      address,
+                                      name);
 }
 
 // Export account has ended with pin generated
 void
 NameDirectoryPrivate::slotExportOnRingEnded(const QString& accountId, int status, const QString& pin)
 {
-    qDebug() << "Export on ring ended for account: " << accountId << "status: " << status
+    LC_DBG << "Export on ring ended for account: " << accountId << "status: " << status
            << "PIN: " << pin;
 
     Q_EMIT q_ptr->exportOnRingEnded(static_cast<NameDirectory::ExportOnRingStatus>(status), pin);
@@ -105,14 +111,18 @@ NameDirectoryPrivate::slotExportOnRingEnded(const QString& accountId, int status
 
 // Lookup a name
 bool
-NameDirectory::lookupName(const QString& accountId, const QString& name, const QString& nameServiceURL) const
+NameDirectory::lookupName(const QString& accountId,
+                          const QString& name,
+                          const QString& nameServiceURL) const
 {
     return ConfigurationManager::instance().lookupName(accountId, nameServiceURL, name);
 }
 
 // Lookup an address
 bool
-NameDirectory::lookupAddress(const QString& accountId, const QString& address, const QString& nameServiceURL) const
+NameDirectory::lookupAddress(const QString& accountId,
+                             const QString& address,
+                             const QString& nameServiceURL) const
 {
     return ConfigurationManager::instance().lookupAddress(accountId, nameServiceURL, address);
 }

src/libclient/typedefs.h

@@ -26,6 +26,15 @@
 #include <QtCore/QDebug>
 #include <QtCore/QDateTime>
 
+#include <QtCore/QLoggingCategory>
+
+Q_DECLARE_LOGGING_CATEGORY(libclientLog)
+#define LC_DBG  qCDebug(libclientLog)
+#define LC_INFO qCInfo(libclientLog)
+#define LC_WARN qCWarning(libclientLog)
+#define LC_ERR  qCCritical(libclientLog)
+#define LC_FATAL qCFatal(libclientLog)
+
 // Typedefs (required to avoid '<' and '>' in the DBus XML)
 typedef QMap<QString, QString> MapStringString;
 typedef QMap<QString, int> MapStringInt;