Add optional timing logs for Shape triangulation

Follow the scenegraph's approach with qt.scenegraph.time.* categories
and add qt.shape.time.sync. When enabled, this will print a line for
each sync() that had something to process. For asynchronous items this
includes all the time from requesting the backend to start the
work right up to the finished callback, and thus can be somewhat
misleading.

Task-number: QTBUG-64951
Change-Id: Ib51a9d4adba4cdc7d692eb7ff14627a5d0e548cf
Reviewed-by: Paolo Angelelli <paolo.angelelli@qt.io>
Reviewed-by: Andy Nichols <andy.nichols@qt.io>

2 files changed, 31 insertions, 3 deletions

diff --git a/src/imports/shapes/qquickshape.cpp b/src/imports/shapes/qquickshape.cpp
index 6a76743242..c749357cc5 100644
--- a/src/imports/shapes/qquickshape.cpp
+++ b/src/imports/shapes/qquickshape.cpp
@@ -46,9 +46,12 @@
 #include <private/qquicksvgparser_p.h>
 #include <QtGui/private/qdrawhelper_p.h>
 #include <QOpenGLFunctions>
+#include <QLoggingCategory>
 
 QT_BEGIN_NAMESPACE
 
+Q_LOGGING_CATEGORY(QQSHAPE_LOG_TIME_DIRTY_SYNC, "qt.shape.time.sync")
+
 /*!
     \qmlmodule QtQuick.Shapes 1.0
     \title Qt Quick Shapes QML Types
@@ -968,18 +971,26 @@ QSGNode *QQuickShapePrivate::createNode()
     return node;
 }
 
-static void q_asyncShapeReady(void *data)
+void QQuickShapePrivate::asyncShapeReady(void *data)
 {
     QQuickShapePrivate *self = static_cast<QQuickShapePrivate *>(data);
     self->setStatus(QQuickShape::Ready);
+    if (self->syncTimingActive)
+        qDebug("[Shape %p] [%d] [dirty=0x%x] async update took %lld ms",
+               self->q_func(), self->syncTimeCounter, self->syncTimingTotalDirty, self->syncTimer.elapsed());
 }
 
 void QQuickShapePrivate::sync()
 {
+    syncTimingTotalDirty = 0;
+    syncTimingActive = QQSHAPE_LOG_TIME_DIRTY_SYNC().isDebugEnabled();
+    if (syncTimingActive)
+        syncTimer.start();
+
     const bool useAsync = async && renderer->flags().testFlag(QQuickAbstractPathRenderer::SupportsAsync);
     if (useAsync) {
         setStatus(QQuickShape::Processing);
-        renderer->setAsyncCallback(q_asyncShapeReady, this);
+        renderer->setAsyncCallback(asyncShapeReady, this);
     }
 
     const int count = sp.count();
@@ -988,6 +999,7 @@ void QQuickShapePrivate::sync()
     for (int i = 0; i < count; ++i) {
         QQuickShapePath *p = sp[i];
         int &dirty(QQuickShapePathPrivate::get(p)->dirty);
+        syncTimingTotalDirty |= dirty;
 
         if (dirty & QQuickShapePathPrivate::DirtyPath)
             renderer->setPath(i, p);
@@ -1011,10 +1023,19 @@ void QQuickShapePrivate::sync()
         dirty = 0;
     }
 
+    if (syncTimingTotalDirty)
+        ++syncTimeCounter;
+    else
+        syncTimingActive = false;
+
     renderer->endSync(useAsync);
 
-    if (!useAsync)
+    if (!useAsync) {
         setStatus(QQuickShape::Ready);
+        if (syncTimingActive)
+            qDebug("[Shape %p] [%d] [dirty=0x%x] update took %lld ms",
+                   q_func(), syncTimeCounter, syncTimingTotalDirty, syncTimer.elapsed());
+    }
 }
 
 // ***** gradient support *****
diff --git a/src/imports/shapes/qquickshape_p_p.h b/src/imports/shapes/qquickshape_p_p.h
index bbe9a81d4a..f43831516a 100644
--- a/src/imports/shapes/qquickshape_p_p.h
+++ b/src/imports/shapes/qquickshape_p_p.h
@@ -56,6 +56,7 @@
 #include <QPainterPath>
 #include <QColor>
 #include <QBrush>
+#include <QElapsedTimer>
 #include <private/qopenglcontext_p.h>
 
 QT_BEGIN_NAMESPACE
@@ -167,6 +168,8 @@ public:
 
     static QQuickShapePrivate *get(QQuickShape *item) { return item->d_func(); }
 
+    static void asyncShapeReady(void *data);
+
     bool spChanged;
     QQuickShape::RendererType rendererType;
     bool async;
@@ -174,6 +177,10 @@ public:
     QQuickAbstractPathRenderer *renderer;
     QVector<QQuickShapePath *> sp;
     bool enableVendorExts;
+    bool syncTimingActive = false;
+    int syncTimingTotalDirty;
+    int syncTimeCounter = 0;
+    QElapsedTimer syncTimer;
 };
 
 #if QT_CONFIG(opengl)