QLibrary/QPlugin/QFactoryLoader: convert to category logging

This adds three categories:
 - qt.core.library
 - qt.core.plugin.loader
 - qt.core.plugin.factoryloader
plus the "qt.core.plugin.elfparser" category (only available in
developer builds).

All three use the new Q_LOGGING_CATEGORY_WITH_ENV_OVERRIDE technique
which enables their debugging if the QT_DEBUG_PLUGINS=1 variable is set.

As a consequence, some warnings were downgraded to debug messages. I've
only left as warnings situations where a real problem occurred, since
they now get printed by default: failures to open or mmap a file,
corrupt plugin metadata (but not scan of non-plugins), use of
QPluginLoader with a static build of Qt.

Drive-by update of some messages to make them prettier and/or use
qUtf16Printable().

Change-Id: I3eb1bd30e0124f89a052fffd16a752acfe89c19e
Reviewed-by: Kai Koehne <kai.koehne@qt.io>

4 files changed, 46 insertions, 68 deletions

diff --git a/src/corelib/plugin/qfactoryloader.cpp b/src/corelib/plugin/qfactoryloader.cpp
index a315daa199..79423251a4 100644
--- a/src/corelib/plugin/qfactoryloader.cpp
+++ b/src/corelib/plugin/qfactoryloader.cpp
@@ -45,6 +45,7 @@
 
 #include "private/qcoreapplication_p.h"
 #include "private/qduplicatetracker_p.h"
+#include "private/qloggingregistry_p.h"
 #include "private/qobject_p.h"
 #include "qcborarray.h"
 #include "qcbormap.h"
@@ -55,7 +56,6 @@
 #include "qjsonarray.h"
 #include "qjsondocument.h"
 #include "qjsonobject.h"
-#include "qjsonvalue.h"
 #include "qmap.h"
 #include "qmutex.h"
 #include "qplugin.h"
@@ -146,6 +146,9 @@ public:
 
 #if QT_CONFIG(library)
 
+static Q_LOGGING_CATEGORY_WITH_ENV_OVERRIDE(lcFactoryLoader, "QT_DEBUG_PLUGINS",
+                                            "qt.core.plugin.factoryloader")
+
 Q_GLOBAL_STATIC(QList<QFactoryLoader *>, qt_factory_loaders)
 
 Q_GLOBAL_STATIC(QRecursiveMutex, qt_factoryloader_mutex)
@@ -173,8 +176,7 @@ void QFactoryLoader::update()
         QString path = pluginDir + d->suffix;
 #endif
 
-        if (qt_debug_component())
-            qDebug() << "QFactoryLoader::QFactoryLoader() checking directory path" << path << "...";
+        qCDebug(lcFactoryLoader) << "checking directory path" << path << "...";
 
         if (!QDir(path).exists(QLatin1String(".")))
             continue;
@@ -210,18 +212,14 @@ void QFactoryLoader::update()
                 continue;
             }
 #endif
-            if (qt_debug_component()) {
-                qDebug() << "QFactoryLoader::QFactoryLoader() looking at" << fileName;
-            }
+            qCDebug(lcFactoryLoader) << "looking at" << fileName;
 
             Q_TRACE(QFactoryLoader_update, fileName);
 
             library = QLibraryPrivate::findOrCreate(QFileInfo(fileName).canonicalFilePath());
             if (!library->isPlugin()) {
-                if (qt_debug_component()) {
-                    qDebug() << library->errorString << Qt::endl
-                             << "         not a plugin";
-                }
+                qCDebug(lcFactoryLoader) << library->errorString << Qt::endl
+                                         << "         not a plugin";
                 library->release();
                 continue;
             }
@@ -238,8 +236,7 @@ void QFactoryLoader::update()
                 for (int i = 0; i < k.size(); ++i)
                     keys += d->cs ? k.at(i).toString() : k.at(i).toString().toLower();
             }
-            if (qt_debug_component())
-                qDebug() << "Got keys from plugin meta data" << keys;
+            qCDebug(lcFactoryLoader) << "Got keys from plugin meta data" << keys;
 
 
             if (!metaDataOk) {
@@ -276,10 +273,8 @@ void QFactoryLoader::update()
     }
 #else
     Q_D(QFactoryLoader);
-    if (qt_debug_component()) {
-        qDebug() << "QFactoryLoader::QFactoryLoader() ignoring" << d->iid
-                 << "since plugins are disabled in static builds";
-    }
+    qCDebug(lcFactoryLoader) << "ignoring" << d->iid
+                             << "since plugins are disabled in static builds";
 #endif
 }
 
diff --git a/src/corelib/plugin/qlibrary.cpp b/src/corelib/plugin/qlibrary.cpp
index 4eea6f0002..5a8c647c27 100644
--- a/src/corelib/plugin/qlibrary.cpp
+++ b/src/corelib/plugin/qlibrary.cpp
@@ -56,6 +56,7 @@
 #  include <private/qcore_mac_p.h>
 #endif
 #include <private/qcoreapplication_p.h>
+#include <private/qloggingregistry_p.h>
 #include <private/qsystemerror_p.h>
 
 #include "qelfparser_p.h"
@@ -82,6 +83,8 @@ static constexpr bool QtBuildIsDebug = false;
 static constexpr bool QtBuildIsDebug = true;
 #endif
 
+Q_LOGGING_CATEGORY_WITH_ENV_OVERRIDE(qt_lcDebugPlugins, "QT_DEBUG_PLUGINS", "qt.core.plugin.loader")
+static Q_LOGGING_CATEGORY_WITH_ENV_OVERRIDE(lcDebugLibrary, "QT_DEBUG_PLUGINS", "qt.core.library")
 
 /*!
     \class QLibrary
@@ -231,10 +234,8 @@ static bool findPatternUnloaded(const QString &library, QLibraryPrivate *lib)
     if (!file.open(QIODevice::ReadOnly)) {
         if (lib)
             lib->errorString = file.errorString();
-        if (qt_debug_component()) {
-            qWarning("%s: %ls", QFile::encodeName(library).constData(),
-                     qUtf16Printable(QSystemError::stdString()));
-        }
+        qCWarning(qt_lcDebugPlugins, "%ls: cannot open: %ls", qUtf16Printable(library),
+                  qUtf16Printable(file.errorString()));
         return false;
     }
 
@@ -250,9 +251,8 @@ static bool findPatternUnloaded(const QString &library, QLibraryPrivate *lib)
     if (filedata == nullptr) {
         // If we can't mmap(), then the dynamic loader won't be able to either.
         // This can't be used as a plugin.
-        if (qt_debug_component())
-            qWarning("%s: failed to map to memory: %ls", QFile::encodeName(library).constData(),
-                     qUtf16Printable(file.errorString()));
+        qCWarning(qt_lcDebugPlugins, "%ls: failed to map to memory: %ls",
+                  qUtf16Printable(library), qUtf16Printable(file.errorString()));
         return false;
     }
 #else
@@ -272,19 +272,17 @@ static bool findPatternUnloaded(const QString &library, QLibraryPrivate *lib)
     if (r.length) {
         if (!lib->metaData.parse(QByteArrayView(filedata + r.pos, r.length))) {
             errMsg = lib->metaData.errorString();
-            qWarning("Found invalid metadata in lib %ls: %ls",
-                     qUtf16Printable(library), qUtf16Printable(errMsg));
+            qCWarning(qt_lcDebugPlugins, "Found invalid metadata in lib %ls: %ls",
+                      qUtf16Printable(library), qUtf16Printable(errMsg));
         } else {
-            if (qt_debug_component()) {
-                QJsonDocument doc(lib->metaData.toJson());
-                qWarning("Found metadata in lib %s, metadata=\n%s\n",
-                         library.toLocal8Bit().constData(), doc.toJson().constData());
-            }
+            qCDebug(qt_lcDebugPlugins, "Found metadata in lib %ls, metadata=\n%s\n",
+                    qUtf16Printable(library),
+                    QJsonDocument(lib->metaData.toJson()).toJson().constData());
             return true;
         }
-    } else if (qt_debug_component()) {
-        qWarning("Failed to find metadata in lib %ls: %ls",
-                 qUtf16Printable(library), qUtf16Printable(errMsg));
+    } else {
+        qCDebug(qt_lcDebugPlugins, "Failed to find metadata in lib %ls: %ls",
+                qUtf16Printable(library), qUtf16Printable(errMsg));
     }
 
     lib->errorString = QLibrary::tr("Failed to extract plugin meta data from '%1': %2")
@@ -310,8 +308,7 @@ static void installCoverageTool(QLibraryPrivate *libPrivate)
 
     int ret = __coveragescanner_register_library(libPrivate->fileName.toLocal8Bit());
 
-    if (qt_debug_component()) {
-        if (ret >= 0) {
+    if (ret >= 0) {
             qDebug("coverage data for %ls registered",
                    qUtf16Printable(libPrivate->fileName));
         } else {
@@ -384,12 +381,13 @@ inline void QLibraryStore::cleanup()
         }
     }
 
-    if (qt_debug_component()) {
-        // dump all objects that remain
+    // dump all objects that remain
+    if (lcDebugLibrary().isDebugEnabled()) {
         for (QLibraryPrivate *lib : qAsConst(data->libraryMap)) {
             if (lib)
-                qDebug() << "On QtCore unload," << lib->fileName << "was leaked, with"
-                         << lib->libraryRefCount.loadRelaxed() << "users";
+                qDebug(lcDebugLibrary)
+                        << "On QtCore unload," << lib->fileName << "was leaked, with"
+                        << lib->libraryRefCount.loadRelaxed() << "users";
         }
     }
 
@@ -538,13 +536,9 @@ bool QLibraryPrivate::load()
     Q_TRACE(QLibraryPrivate_load_entry, fileName);
 
     bool ret = load_sys();
-    if (qt_debug_component()) {
-        if (ret) {
-            qDebug() << "loaded library" << fileName;
-        } else {
-            qDebug() << qUtf8Printable(errorString);
-        }
-    }
+    qCDebug(lcDebugLibrary)
+            << fileName
+            << (ret ? "loaded library" : qUtf8Printable(u"cannot load: " + errorString));
     if (ret) {
         //when loading a library we add a reference to it so that the QLibraryPrivate won't get deleted
         //this allows to unload the library at a later time
@@ -566,9 +560,8 @@ bool QLibraryPrivate::unload(UnloadFlag flag)
         QMutexLocker locker(&mutex);
         delete inst.data();
         if (flag == NoUnloadSys || unload_sys()) {
-            if (qt_debug_component())
-                qWarning() << "QLibraryPrivate::unload succeeded on" << fileName
-                           << (flag == NoUnloadSys ? "(faked)" : "");
+            qCDebug(lcDebugLibrary) << fileName << "unloaded library"
+                                    << (flag == NoUnloadSys ? "(faked)" : "");
             // when the library is unloaded, we release the reference on it so that 'this'
             // can get deleted
             libraryRefCount.deref();
@@ -599,8 +592,7 @@ QtPluginInstanceFunction QLibraryPrivate::loadPlugin()
         instanceFactory.storeRelease(ptr); // two threads may store the same value
         return ptr;
     }
-    if (qt_debug_component())
-        qWarning() << "QLibraryPrivate::loadPlugin failed on" << fileName << ":" << errorString;
+    qCDebug(qt_lcDebugPlugins) << "QLibraryPrivate::loadPlugin failed on" << fileName << ":" << errorString;
     pluginState = IsNotAPlugin;
     return nullptr;
 }
@@ -773,13 +765,11 @@ void QLibraryPrivate::updatePluginState()
     uint qt_version = uint(metaData.value(QtPluginMetaDataKeys::QtVersion).toInteger());
     bool debug = metaData.value(QtPluginMetaDataKeys::IsDebug).toBool();
     if ((qt_version & 0x00ff00) > (QT_VERSION & 0x00ff00) || (qt_version & 0xff0000) != (QT_VERSION & 0xff0000)) {
-        if (qt_debug_component()) {
-            qWarning("In %s:\n"
+        qCWarning(qt_lcDebugPlugins, "In %s:\n"
                  "  Plugin uses incompatible Qt library (%d.%d.%d) [%s]",
                  QFile::encodeName(fileName).constData(),
                  (qt_version&0xff0000) >> 16, (qt_version&0xff00) >> 8, qt_version&0xff,
                  debug ? "debug" : "release");
-        }
         errorString = QLibrary::tr("The plugin '%1' uses incompatible Qt library. (%2.%3.%4) [%5]")
             .arg(fileName)
             .arg((qt_version&0xff0000) >> 16)
diff --git a/src/corelib/plugin/qlibrary_p.h b/src/corelib/plugin/qlibrary_p.h
index 3c43d79e25..42d3d7256d 100644
--- a/src/corelib/plugin/qlibrary_p.h
+++ b/src/corelib/plugin/qlibrary_p.h
@@ -55,6 +55,7 @@
 #include "QtCore/qlibrary.h"
 
 #include "QtCore/private/qfactoryloader_p.h"
+#include "QtCore/qloggingcategory.h"
 #include "QtCore/qmutex.h"
 #include "QtCore/qplugin.h"
 #include "QtCore/qpointer.h"
@@ -67,7 +68,7 @@ QT_REQUIRE_CONFIG(library);
 
 QT_BEGIN_NAMESPACE
 
-bool qt_debug_component();
+Q_DECLARE_LOGGING_CATEGORY(qt_lcDebugPlugins)
 
 struct QLibraryScanResult
 {
diff --git a/src/corelib/plugin/qpluginloader.cpp b/src/corelib/plugin/qpluginloader.cpp
index eca85eb82e..fb69142149 100644
--- a/src/corelib/plugin/qpluginloader.cpp
+++ b/src/corelib/plugin/qpluginloader.cpp
@@ -271,8 +271,6 @@ static QString locatePlugin(const QString& fileName)
     const auto baseName = QStringView{fileName}.mid(slash + 1);
     const auto basePath = isAbsolute ? QStringView() : QStringView{fileName}.left(slash + 1); // keep the '/'
 
-    const bool debug = qt_debug_component();
-
     QStringList paths;
     if (isAbsolute) {
         paths.append(fileName.left(slash)); // don't include the '/'
@@ -287,22 +285,19 @@ static QString locatePlugin(const QString& fileName)
                 {
                     QString pluginPath = basePath + prefix + baseName + suffix;
                     const QString fn = path + QLatin1String("/lib") + pluginPath.replace(QLatin1Char('/'), QLatin1Char('_'));
-                    if (debug)
-                        qDebug() << "Trying..." << fn;
+                    qCDebug(qt_lcDebugPlugins) << "Trying..." << fn;
                     if (QFileInfo(fn).isFile())
                         return fn;
                 }
 #endif
                 const QString fn = path + QLatin1Char('/') + basePath + prefix + baseName + suffix;
-                if (debug)
-                    qDebug() << "Trying..." << fn;
+                qCDebug(qt_lcDebugPlugins) << "Trying..." << fn;
                 if (QFileInfo(fn).isFile())
                     return fn;
             }
         }
     }
-    if (debug)
-        qDebug() << fileName << "not found";
+    qCDebug(qt_lcDebugPlugins) << fileName << "not found";
     return QString();
 }
 #endif
@@ -347,11 +342,8 @@ void QPluginLoader::setFileName(const QString &fileName)
         d->updatePluginState();
 
 #else
-    if (qt_debug_component()) {
-        qWarning("Cannot load %s into a statically linked Qt library.",
-                 (const char *)QFile::encodeName(fileName));
-    }
-    Q_UNUSED(fileName);
+    qCWarning(qt_lcDebugPlugins, "Cannot load '%ls' into a statically linked Qt library.",
+              qUtf16Printable(fileName));
 #endif
 }