rhi: Move info prints to categorized logging

Following the Quick scenegraph (qt.scenegraph.*), we now have
qt.rhi.general. Other categories may get added later.

This does not change the printing of real errors, those will
continue to use qWarning().

Change-Id: Id95416fc82ba8add9527212e431bcbd47d416f1a
Reviewed-by: Andy Nichols <andy.nichols@qt.io>

6 files changed, 53 insertions, 19 deletions

diff --git a/src/gui/rhi/qrhi.cpp b/src/gui/rhi/qrhi.cpp
index 3576b30349..7770cac870 100644
--- a/src/gui/rhi/qrhi.cpp
+++ b/src/gui/rhi/qrhi.cpp
@@ -36,6 +36,7 @@
 
 #include "qrhi_p_p.h"
 #include <qmath.h>
+#include <QLoggingCategory>
 
 #include "qrhinull_p_p.h"
 #ifndef QT_NO_OPENGL
@@ -54,6 +55,8 @@
 
 QT_BEGIN_NAMESPACE
 
+Q_LOGGING_CATEGORY(QRHI_LOG_INFO, "qt.rhi.general")
+
 /*!
     \class QRhi
     \inmodule QtRhi
@@ -389,6 +392,22 @@ QT_BEGIN_NAMESPACE
     texture object is "exported" via QRhi::nativeHandles() or
     QRhiTexture::nativeHandles(). Most importantly, passing pointers in structs
     and via setters does not transfer ownership.
+
+    \section2 Troubleshooting
+
+    Errors are printed to the output via qWarning(). Additional debug messages
+    can be enabled via the following logging categories. Messages from these
+    categories are not printed by default unless explicitly enabled via
+    QRhi::EnableProfiling or the facilities of QLoggingCategory (such as, the
+    \c QT_LOGGING_RULES environment variable).
+
+    \list
+    \li \c{qt.rhi.general}
+    \endlist
+
+    It is strongly advised to inspect the output with the logging categories
+    (\c{qt.rhi.*}) enabled whenever a QRhi-based application is not behaving as
+    expected.
  */
 
 /*!
@@ -409,7 +428,8 @@ QT_BEGIN_NAMESPACE
     \value EnableProfiling Enables gathering timing (CPU, GPU) and resource
     (QRhiBuffer, QRhiTexture, etc.) information and additional metadata. See
     QRhiProfiler. Avoid enabling in production builds as it may involve a
-    performance penalty.
+    performance penalty. Also enables debug messages from the \c{qt.rhi.*}
+    logging categories.
 
     \value EnableDebugMarkers Enables debug marker groups. Without this frame
     debugging features like making debug groups and custom resource name
@@ -3873,11 +3893,21 @@ QRhi *QRhi::create(Implementation impl, QRhiInitParams *params, Flags flags, QRh
 
     if (r->d) {
         r->d->q = r.data();
+
         if (flags.testFlag(EnableProfiling)) {
             QRhiProfilerPrivate *profD = QRhiProfilerPrivate::get(&r->d->profiler);
             profD->rhiDWhenEnabled = r->d;
+            const_cast<QLoggingCategory &>(QRHI_LOG_INFO()).setEnabled(QtDebugMsg, true);
         }
+
+        // Play nice with QSG_INFO since that is still the most commonly used
+        // way to get graphics info printed from Qt Quick apps, and the Quick
+        // scenegraph is our primary user.
+        if (qEnvironmentVariableIsSet("QSG_INFO"))
+            const_cast<QLoggingCategory &>(QRHI_LOG_INFO()).setEnabled(QtDebugMsg, true);
+
         r->d->debugMarkers = flags.testFlag(EnableDebugMarkers);
+
         if (r->d->create(flags)) {
             r->d->implType = impl;
             r->d->implThread = QThread::currentThread();
diff --git a/src/gui/rhi/qrhi_p_p.h b/src/gui/rhi/qrhi_p_p.h
index d87c4372ca..b592fe82f2 100644
--- a/src/gui/rhi/qrhi_p_p.h
+++ b/src/gui/rhi/qrhi_p_p.h
@@ -52,6 +52,7 @@
 #include "qrhiprofiler_p_p.h"
 #include <QBitArray>
 #include <QAtomicInt>
+#include <QLoggingCategory>
 
 QT_BEGIN_NAMESPACE
 
@@ -60,6 +61,8 @@ QT_BEGIN_NAMESPACE
 #define QRHI_PROF QRhiProfilerPrivate *rhiP = m_rhi->profilerPrivateOrNull()
 #define QRHI_PROF_F(f) for (bool qrhip_enabled = rhiP != nullptr; qrhip_enabled; qrhip_enabled = false) rhiP->f
 
+Q_DECLARE_LOGGING_CATEGORY(QRHI_LOG_INFO)
+
 class QRhiImplementation
 {
 public:
diff --git a/src/gui/rhi/qrhid3d11.cpp b/src/gui/rhi/qrhid3d11.cpp
index a8a490eb5c..0c5df600a0 100644
--- a/src/gui/rhi/qrhid3d11.cpp
+++ b/src/gui/rhi/qrhid3d11.cpp
@@ -189,10 +189,10 @@ bool QRhiD3D11::create(QRhi::Flags flags)
             DXGI_ADAPTER_DESC1 desc;
             adapter->GetDesc1(&desc);
             const QString name = QString::fromUtf16((char16_t *) desc.Description);
-            qDebug("Adapter %d: '%s' (flags 0x%x)", adapterIndex, qPrintable(name), desc.Flags);
+            qCDebug(QRHI_LOG_INFO, "Adapter %d: '%s' (flags 0x%x)", adapterIndex, qPrintable(name), desc.Flags);
             if (!adapterToUse && (requestedAdapterIndex < 0 || requestedAdapterIndex == adapterIndex)) {
                 adapterToUse = adapter;
-                qDebug("  using this adapter");
+                qCDebug(QRHI_LOG_INFO, "  using this adapter");
             } else {
                 adapter->Release();
             }
diff --git a/src/gui/rhi/qrhigles2.cpp b/src/gui/rhi/qrhigles2.cpp
index 3ef4bb3a07..929f3fe21d 100644
--- a/src/gui/rhi/qrhigles2.cpp
+++ b/src/gui/rhi/qrhigles2.cpp
@@ -385,7 +385,7 @@ bool QRhiGles2::create(QRhi::Flags flags)
             ctx = nullptr;
             return false;
         }
-        qDebug() << "Created OpenGL context" << ctx->format();
+        qCDebug(QRHI_LOG_INFO) << "Created OpenGL context" << ctx->format();
     }
 
     if (!ensureContext(maybeWindow ? maybeWindow : fallbackSurface)) // see 'window' discussion in QRhiGles2InitParams comments
@@ -397,7 +397,7 @@ bool QRhiGles2::create(QRhi::Flags flags)
     const char *renderer = reinterpret_cast<const char *>(f->glGetString(GL_RENDERER));
     const char *version = reinterpret_cast<const char *>(f->glGetString(GL_VERSION));
     if (vendor && renderer && version)
-        qDebug("OpenGL VENDOR: %s RENDERER: %s VERSION: %s", vendor, renderer, version);
+        qCDebug(QRHI_LOG_INFO, "OpenGL VENDOR: %s RENDERER: %s VERSION: %s", vendor, renderer, version);
 
     const QSurfaceFormat actualFormat = ctx->format();
 
diff --git a/src/gui/rhi/qrhimetal.mm b/src/gui/rhi/qrhimetal.mm
index 98b2a9bcac..ffb2283ae7 100644
--- a/src/gui/rhi/qrhimetal.mm
+++ b/src/gui/rhi/qrhimetal.mm
@@ -353,7 +353,7 @@ bool QRhiMetal::create(QRhi::Flags flags)
     else
         d->dev = MTLCreateSystemDefaultDevice();
 
-    qDebug("Metal device: %s", qPrintable(QString::fromNSString([d->dev name])));
+    qCDebug(QRHI_LOG_INFO, "Metal device: %s", qPrintable(QString::fromNSString([d->dev name])));
 
     if (importedCmdQueue)
         [d->cmdQueue retain];
@@ -3538,7 +3538,7 @@ bool QMetalSwapChain::buildOrResize()
     rtWrapper.d->colorAttCount = 1;
     rtWrapper.d->dsAttCount = ds ? 1 : 0;
 
-    qDebug("got CAMetalLayer, size %dx%d", pixelSize.width(), pixelSize.height());
+    qCDebug(QRHI_LOG_INFO, "got CAMetalLayer, size %dx%d", pixelSize.width(), pixelSize.height());
 
     if (samples > 1) {
         MTLTextureDescriptor *desc = [[MTLTextureDescriptor alloc] init];
diff --git a/src/gui/rhi/qrhivulkan.cpp b/src/gui/rhi/qrhivulkan.cpp
index f48a8a3cfe..61a1595a50 100644
--- a/src/gui/rhi/qrhivulkan.cpp
+++ b/src/gui/rhi/qrhivulkan.cpp
@@ -360,14 +360,14 @@ bool QRhiVulkan::create(QRhi::Flags flags)
             requestedPhysDevIndex = qEnvironmentVariableIntValue("QT_VK_PHYSICAL_DEVICE_INDEX");
         for (uint32_t i = 0; i < physDevCount; ++i) {
             f->vkGetPhysicalDeviceProperties(physDevs[i], &physDevProperties);
-            qDebug("Physical device %d: '%s' %d.%d.%d", i,
-                   physDevProperties.deviceName,
-                   VK_VERSION_MAJOR(physDevProperties.driverVersion),
-                   VK_VERSION_MINOR(physDevProperties.driverVersion),
-                   VK_VERSION_PATCH(physDevProperties.driverVersion));
+            qCDebug(QRHI_LOG_INFO, "Physical device %d: '%s' %d.%d.%d", i,
+                    physDevProperties.deviceName,
+                    VK_VERSION_MAJOR(physDevProperties.driverVersion),
+                    VK_VERSION_MINOR(physDevProperties.driverVersion),
+                    VK_VERSION_PATCH(physDevProperties.driverVersion));
             if (physDevIndex < 0 && (requestedPhysDevIndex < 0 || requestedPhysDevIndex == int(i))) {
                 physDevIndex = i;
-                qDebug("    using this physical device");
+                qCDebug(QRHI_LOG_INFO, "    using this physical device");
             }
         }
         if (physDevIndex < 0) {
@@ -386,7 +386,8 @@ bool QRhiVulkan::create(QRhi::Flags flags)
         gfxQueueFamilyIdx = -1;
         int computelessGfxQueueCandidateIdx = -1;
         for (int i = 0; i < queueFamilyProps.count(); ++i) {
-            qDebug("queue family %d: flags=0x%x count=%d", i, queueFamilyProps[i].queueFlags, queueFamilyProps[i].queueCount);
+            qCDebug(QRHI_LOG_INFO, "queue family %d: flags=0x%x count=%d",
+                    i, queueFamilyProps[i].queueFlags, queueFamilyProps[i].queueCount);
             if (gfxQueueFamilyIdx == -1
                     && (queueFamilyProps[i].queueFlags & VK_QUEUE_GRAPHICS_BIT)
                     && (!maybeWindow || inst->supportsPresent(physDev, i, maybeWindow)))
@@ -422,7 +423,7 @@ bool QRhiVulkan::create(QRhi::Flags flags)
         f->vkEnumerateDeviceExtensionProperties(physDev, nullptr, &devExtCount, nullptr);
         QVector<VkExtensionProperties> devExts(devExtCount);
         f->vkEnumerateDeviceExtensionProperties(physDev, nullptr, &devExtCount, devExts.data());
-        qDebug("%d device extensions available", devExts.count());
+        qCDebug(QRHI_LOG_INFO, "%d device extensions available", devExts.count());
 
         QVector<const char *> requestedDevExts;
         requestedDevExts.append("VK_KHR_swapchain");
@@ -1244,9 +1245,9 @@ bool QRhiVulkan::recreateSwapChain(QRhiSwapChain *swapChain)
     // with VK_ERROR_NATIVE_WINDOW_IN_USE_KHR if the old swapchain is provided)
     const bool reuseExisting = swapChainD->sc && swapChainD->lastConnectedSurface == swapChainD->surface;
 
-    qDebug("Creating %s swapchain of %u buffers, size %dx%d, presentation mode %d",
-           reuseExisting ? "recycled" : "new",
-           reqBufferCount, swapChainD->pixelSize.width(), swapChainD->pixelSize.height(), presentMode);
+    qCDebug(QRHI_LOG_INFO, "Creating %s swapchain of %u buffers, size %dx%d, presentation mode %d",
+            reuseExisting ? "recycled" : "new",
+            reqBufferCount, swapChainD->pixelSize.width(), swapChainD->pixelSize.height(), presentMode);
 
     VkSwapchainCreateInfoKHR swapChainInfo;
     memset(&swapChainInfo, 0, sizeof(swapChainInfo));
@@ -1290,7 +1291,7 @@ bool QRhiVulkan::recreateSwapChain(QRhiSwapChain *swapChain)
         return false;
     }
     if (actualSwapChainBufferCount != reqBufferCount)
-        qDebug("Actual swapchain buffer count is %u", actualSwapChainBufferCount);
+        qCDebug(QRHI_LOG_INFO, "Actual swapchain buffer count is %u", actualSwapChainBufferCount);
     swapChainD->bufferCount = actualSwapChainBufferCount;
 
     VkImage swapChainImages[QVkSwapChain::MAX_BUFFER_COUNT];