Qml Preview: Record more detailed frame statistics

Just the number of frames per second doesn't tell us the reason for any
low frame rates. The problem could either be GPU-bound, and rendering
could take very long, or the problem could be CPU-bound, with
synchronizing or the gap between frames being very long.

Reporting the rendering and synchronization times in more detail gives
the client an idea of what is actually going on.

Change-Id: Ib2840a9e1aa9b9738e967730c668769946659be2
Reviewed-by: Thomas Hartmann <thomas.hartmann@qt.io>

4 files changed, 124 insertions, 10 deletions

diff --git a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.cpp b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.cpp
index 21d415bbb6..082bd01fd0 100644
--- a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.cpp
+++ b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.cpp
@@ -347,30 +347,106 @@ void QQmlPreviewHandler::setCurrentWindow(QQuickWindow *window)
         return;
 
     if (m_currentWindow) {
+        disconnect(m_currentWindow.data(), &QQuickWindow::beforeSynchronizing,
+                   this, &QQmlPreviewHandler::beforeSynchronizing);
+        disconnect(m_currentWindow.data(), &QQuickWindow::afterSynchronizing,
+                   this, &QQmlPreviewHandler::afterSynchronizing);
+        disconnect(m_currentWindow.data(), &QQuickWindow::beforeRendering,
+                   this, &QQmlPreviewHandler::beforeRendering);
         disconnect(m_currentWindow.data(), &QQuickWindow::frameSwapped,
                    this, &QQmlPreviewHandler::frameSwapped);
         m_fpsTimer.stop();
-        m_frames = 0;
+        m_rendering = FrameTime();
+        m_synchronizing = FrameTime();
     }
 
     m_currentWindow = window;
 
     if (m_currentWindow) {
+        connect(m_currentWindow.data(), &QQuickWindow::beforeSynchronizing,
+                this, &QQmlPreviewHandler::beforeSynchronizing, Qt::DirectConnection);
+        connect(m_currentWindow.data(), &QQuickWindow::afterSynchronizing,
+                this, &QQmlPreviewHandler::afterSynchronizing, Qt::DirectConnection);
+        connect(m_currentWindow.data(), &QQuickWindow::beforeRendering,
+                this, &QQmlPreviewHandler::beforeRendering, Qt::DirectConnection);
         connect(m_currentWindow.data(), &QQuickWindow::frameSwapped,
-                this, &QQmlPreviewHandler::frameSwapped);
+                this, &QQmlPreviewHandler::frameSwapped, Qt::DirectConnection);
         m_fpsTimer.start();
     }
 }
 
+void QQmlPreviewHandler::beforeSynchronizing()
+{
+    m_synchronizing.beginFrame();
+}
+
+void QQmlPreviewHandler::afterSynchronizing()
+{
+
+    if (m_rendering.elapsed >= 0)
+        m_rendering.endFrame();
+    m_synchronizing.recordFrame();
+    m_synchronizing.endFrame();
+}
+
+void QQmlPreviewHandler::beforeRendering()
+{
+    m_rendering.beginFrame();
+}
+
 void QQmlPreviewHandler::frameSwapped()
 {
-    ++m_frames;
+    m_rendering.recordFrame();
+}
+
+void QQmlPreviewHandler::FrameTime::beginFrame()
+{
+    timer.start();
+}
+
+void QQmlPreviewHandler::FrameTime::recordFrame()
+{
+    elapsed = timer.elapsed();
+}
+
+void QQmlPreviewHandler::FrameTime::endFrame()
+{
+    if (elapsed < min)
+        min = static_cast<quint16>(qMax(0ll, elapsed));
+    if (elapsed > max)
+        max = static_cast<quint16>(qMin(qint64(std::numeric_limits<quint16>::max()), elapsed));
+    total = static_cast<quint16>(qBound(0ll, qint64(std::numeric_limits<quint16>::max()),
+                                        elapsed + total));
+    ++number;
+    elapsed = -1;
+}
+
+void QQmlPreviewHandler::FrameTime::reset()
+{
+    min = std::numeric_limits<quint16>::max();
+    max = 0;
+    total = 0;
+    number = 0;
 }
 
 void QQmlPreviewHandler::fpsTimerHit()
 {
-    emit fps(m_frames);
-    m_frames = 0;
+    const FpsInfo info = {
+        m_synchronizing.number,
+        m_synchronizing.min,
+        m_synchronizing.max,
+        m_synchronizing.total,
+
+        m_rendering.number,
+        m_rendering.min,
+        m_rendering.max,
+        m_rendering.total
+    };
+
+    emit fps(info);
+
+    m_rendering.reset();
+    m_synchronizing.reset();
 }
 
 void QQmlPreviewHandler::tryCreateObject()
diff --git a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.h b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.h
index d5888d67a4..7526b11cd7 100644
--- a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.h
+++ b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewhandler.h
@@ -46,6 +46,7 @@
 #include <QtCore/qvector.h>
 #include <QtCore/qrect.h>
 #include <QtCore/qpointer.h>
+#include <QtCore/qelapsedtimer.h>
 #include <QtQml/qqmlengine.h>
 
 QT_BEGIN_NAMESPACE
@@ -73,9 +74,21 @@ public:
 
     void clear();
 
+    struct FpsInfo {
+        quint16 numSyncs;
+        quint16 minSync;
+        quint16 maxSync;
+        quint16 totalSync;
+
+        quint16 numRenders;
+        quint16 minRender;
+        quint16 maxRender;
+        quint16 totalRender;
+    };
+
 signals:
     void error(const QString &message);
-    void fps(quint16 frames);
+    void fps(const FpsInfo &info);
 
 protected:
     bool eventFilter(QObject *obj, QEvent *event);
@@ -83,7 +96,12 @@ private:
     void tryCreateObject();
     void showObject(QObject *object);
     void setCurrentWindow(QQuickWindow *window);
+
+    void beforeSynchronizing();
+    void afterSynchronizing();
+    void beforeRendering();
     void frameSwapped();
+
     void fpsTimerHit();
     void removeTranslators();
 
@@ -96,7 +114,23 @@ private:
     QQmlPreviewPosition m_lastPosition;
 
     QTimer m_fpsTimer;
-    quint16 m_frames = 0;
+
+    struct FrameTime {
+        void beginFrame();
+        void recordFrame();
+        void endFrame();
+        void reset();
+
+        QElapsedTimer timer;
+        qint64 elapsed = -1;
+        quint16 min = std::numeric_limits<quint16>::max();
+        quint16 max = 0;
+        quint16 total = 0;
+        quint16 number = 0;
+    };
+
+    FrameTime m_rendering;
+    FrameTime m_synchronizing;
 
     QScopedPointer<QTranslator> m_qtTranslator;
     QScopedPointer<QTranslator> m_qmlTranslator;
@@ -104,4 +138,6 @@ private:
 
 QT_END_NAMESPACE
 
+Q_DECLARE_METATYPE(QQmlPreviewHandler::FpsInfo)
+
 #endif // QQMLPREVIEWHANDLER_H
diff --git a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.cpp b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.cpp
index b6074f5712..937ca48456 100644
--- a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.cpp
+++ b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.cpp
@@ -172,10 +172,12 @@ void QQmlPreviewServiceImpl::forwardError(const QString &error)
     emit messageToClient(name(), packet.data());
 }
 
-void QQmlPreviewServiceImpl::forwardFps(quint16 frames)
+void QQmlPreviewServiceImpl::forwardFps(const QQmlPreviewHandler::FpsInfo &frames)
 {
     QQmlDebugPacket packet;
-    packet << static_cast<qint8>(Fps) << frames;
+    packet << static_cast<qint8>(Fps)
+           << frames.numSyncs << frames.minSync << frames.maxSync << frames.totalSync
+           << frames.numRenders << frames.minRender << frames.maxRender << frames.totalRender;
     emit messageToClient(name(), packet.data());
 }
 
diff --git a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.h b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.h
index 4ddbf949b7..b13ef43501 100644
--- a/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.h
+++ b/src/plugins/qmltooling/qmldbg_preview/qqmlpreviewservice.h
@@ -78,7 +78,7 @@ public:
 
     void forwardRequest(const QString &file);
     void forwardError(const QString &error);
-    void forwardFps(quint16 frames);
+    void forwardFps(const QQmlPreviewHandler::FpsInfo &frames);
 
 signals:
     void error(const QString &file);