widgets: Add logging for widget painting

Change-Id: I551ec290812369e3848c1096fed7e813cd9e1cd6
Reviewed-by: Paul Olav Tvete <paul.tvete@qt.io>

src/widgets/kernel/qwidget.cpp

@@ -119,6 +119,8 @@
 
 QT_BEGIN_NAMESPACE
 
+Q_LOGGING_CATEGORY(lcWidgetPainting, "qt.widgets.painting", QtWarningMsg);
+
 static inline bool qRectIntersects(const QRect &r1, const QRect &r2)
 {
     return (qMax(r1.left(), r2.left()) <= qMin(r1.right(), r2.right()) &&
@@ -5273,10 +5275,14 @@ void QWidgetPrivate::drawWidget(QPaintDevice *pdev, const QRegion &rgn, const QP
     if (rgn.isEmpty())
         return;
 
+    Q_Q(QWidget);
+
+    qCInfo(lcWidgetPainting) << "Drawing" << rgn << "of" << q << "at" << offset
+        << "into paint device" << pdev << "with" << flags;
+
     const bool asRoot = flags & DrawAsRoot;
     bool onScreen = shouldPaintOnScreen();
 
-    Q_Q(QWidget);
 #if QT_CONFIG(graphicseffect)
     if (graphicsEffect && graphicsEffect->isEnabled()) {
         QGraphicsEffectSource *source = graphicsEffect->d_func()->source;

src/widgets/kernel/qwidget_p.h

@@ -80,6 +80,8 @@
 
 QT_BEGIN_NAMESPACE
 
+Q_DECLARE_LOGGING_CATEGORY(lcWidgetPainting);
+
 // Extra QWidget data
 //  - to minimize memory usage for members that are seldom used.
 //  - top-level widgets have extra extra data to reduce cost further

src/widgets/kernel/qwidgetrepaintmanager.cpp

@@ -206,6 +206,9 @@ static inline QRect widgetRectFor(QWidget *widget, const QRegion &) { return wid
 template <class T>
 void QWidgetRepaintManager::markDirty(const T &r, QWidget *widget, UpdateTime updateTime, BufferState bufferState)
 {
+    qCInfo(lcWidgetPainting) << "Marking" << r << "of" << widget << "dirty"
+        << "with" << updateTime;
+
     Q_ASSERT(tlw->d_func()->extra);
     Q_ASSERT(tlw->d_func()->extra->topextra);
     Q_ASSERT(!tlw->d_func()->extra->topextra->inTopLevelResize);
@@ -370,6 +373,8 @@ void QWidgetRepaintManager::sendUpdateRequest(QWidget *widget, UpdateTime update
     if (!widget)
         return;
 
+    qCInfo(lcWidgetPainting) << "Sending update request to" << widget << "with" << updateTime;
+
 #ifndef QT_NO_OPENGL
     // Having every repaint() leading to a sync/flush is bad as it causes
     // compositing and waiting for vsync each and every time. Change to
@@ -713,6 +718,8 @@ static QPlatformTextureList *widgetTexturesFor(QWidget *tlw, QWidget *widget)
 */
 void QWidgetRepaintManager::sync(QWidget *exposedWidget, const QRegion &exposedRegion)
 {
+    qCInfo(lcWidgetPainting) << "Syncing" << exposedRegion << "of" << exposedWidget;
+
     QTLWExtra *tlwExtra = tlw->d_func()->maybeTopData();
     if (!tlw->isVisible() || !tlwExtra || tlwExtra->inTopLevelResize)
         return;
@@ -745,6 +752,8 @@ void QWidgetRepaintManager::sync(QWidget *exposedWidget, const QRegion &exposedR
 */
 void QWidgetRepaintManager::sync()
 {
+    qCInfo(lcWidgetPainting) << "Syncing dirty widgets";
+
     updateRequestSent = false;
     if (qt_widget_private(tlw)->shouldDiscardSyncRequest()) {
         // If the top-level is minimized, it's not visible on the screen so we can delay the
@@ -798,6 +807,9 @@ bool QWidgetRepaintManager::syncAllowed()
 
 void QWidgetRepaintManager::paintAndFlush()
 {
+    qCInfo(lcWidgetPainting) << "Painting and flushing dirty"
+        << "top level" << dirty << "and dirty widgets" << dirtyWidgets;
+
     const bool updatesDisabled = !tlw->updatesEnabled();
     bool repaintAllWidgets = false;
 
@@ -1027,10 +1039,15 @@ void QWidgetRepaintManager::markNeedsFlush(QWidget *widget, const QRegion &regio
 
     if (widget == tlw) {
         // Top-level (native)
+        qCInfo(lcWidgetPainting) << "Marking" << region << "of top level"
+            << widget << "as needing flush";
         if (!widget->testAttribute(Qt::WA_WState_InPaintEvent))
             topLevelNeedsFlush += region;
     } else if (!hasPlatformWindow(widget) && !widget->isWindow()) {
         QWidget *nativeParent = widget->nativeParentWidget();
+        qCInfo(lcWidgetPainting) << "Marking" << region << "of"
+                << widget << "as needing flush in" << nativeParent
+                << "at offset" << topLevelOffset;
         if (nativeParent == tlw) {
             // Alien widgets with the top-level as the native parent (common case)
             if (!widget->testAttribute(Qt::WA_WState_InPaintEvent))
@@ -1042,6 +1059,8 @@ void QWidgetRepaintManager::markNeedsFlush(QWidget *widget, const QRegion &regio
         }
     } else {
         // Native child widgets
+        qCInfo(lcWidgetPainting) << "Marking" << region
+            << "of native child" << widget << "as needing flush";
         markNeedsFlush(widget, region);
     }
 }
@@ -1066,6 +1085,9 @@ void QWidgetRepaintManager::markNeedsFlush(QWidget *widget, const QRegion &regio
 */
 void QWidgetRepaintManager::flush()
 {
+    qCInfo(lcWidgetPainting) << "Flushing top level"
+        << topLevelNeedsFlush << "and children" << needsFlushWidgets;
+
     const bool hasNeedsFlushWidgets = !needsFlushWidgets.isEmpty();
     bool flushed = false;
 
@@ -1123,6 +1145,8 @@ void QWidgetRepaintManager::flush(QWidget *widget, const QRegion &region, QPlatf
             return;
     }
 
+    qCInfo(lcWidgetPainting) << "Flushing" << region << "of" << widget;
+
     static bool fpsDebug = qEnvironmentVariableIntValue("QT_DEBUG_FPS");
     if (fpsDebug) {
         if (!perfFrames++)

src/widgets/kernel/qwidgetrepaintmanager_p.h

@@ -65,16 +65,19 @@ class QWidgetRepaintManager;
 
 class Q_AUTOTEST_EXPORT QWidgetRepaintManager
 {
+    Q_GADGET
 public:
     enum UpdateTime {
         UpdateNow,
         UpdateLater
     };
+    Q_ENUM(UpdateTime)
 
     enum BufferState{
         BufferValid,
         BufferInvalid
     };
+    Q_ENUM(BufferState)
 
     QWidgetRepaintManager(QWidget *t);
     ~QWidgetRepaintManager();