QmlProfiler: Explicitly specify the offsets for scene graph events

The profiler can be switched on in the middle of a frame. In that case
the last offset into the timing data would be some random number, which
may lead to a crash when recording the sample.
However, as we know all the data points we are going to record, we can
as well specify where they are supposed to go. The timings themselves
may still be random for frames of which we only recorded parts, but
the clients can deal with this.

Task-number: QTBUG-57304
Change-Id: I1d507f2591516e43d5b3cd25f7939716f2b64ed9
Reviewed-by: Simon Hausmann <simon.hausmann@qt.io>

8 files changed, 76 insertions, 38 deletions

diff --git a/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp b/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp
index 525d702a76..45fb857fb3 100644
--- a/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp
+++ b/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp
@@ -163,7 +163,8 @@ ShaderManager::Shader *ShaderManager::prepareMaterial(QSGMaterial *material)
 
     qCDebug(QSG_LOG_TIME_COMPILATION, "shader compiled in %dms", (int) qsg_renderer_timer.elapsed());
 
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphContextFrame);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphContextFrame,
+                           QQuickProfiler::SceneGraphContextMaterialCompile);
 
     rewrittenShaders[type] = shader;
     return shader;
@@ -194,7 +195,8 @@ ShaderManager::Shader *ShaderManager::prepareMaterialNoRewrite(QSGMaterial *mate
 
     qCDebug(QSG_LOG_TIME_COMPILATION, "shader compiled in %dms (no rewrite)", (int) qsg_renderer_timer.elapsed());
 
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphContextFrame);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphContextFrame,
+                           QQuickProfiler::SceneGraphContextMaterialCompile);
     return shader;
 }
 
diff --git a/src/quick/scenegraph/coreapi/qsgrenderer.cpp b/src/quick/scenegraph/coreapi/qsgrenderer.cpp
index 775277e588..bd60454a50 100644
--- a/src/quick/scenegraph/coreapi/qsgrenderer.cpp
+++ b/src/quick/scenegraph/coreapi/qsgrenderer.cpp
@@ -199,7 +199,8 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
     bindable.bind();
     if (profileFrames)
         bindTime = frameTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRendererFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRendererFrame,
+                              QQuickProfiler::SceneGraphRendererBinding);
 
     // Sanity check that attribute registers are disabled
     if (qsg_sanity_check) {
@@ -217,7 +218,8 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
     render();
     if (profileFrames)
         renderTime = frameTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphRendererFrame);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphRendererFrame,
+                           QQuickProfiler::SceneGraphRendererRender);
 
     m_is_rendering = false;
     m_changed_emitted = false;
@@ -281,13 +283,15 @@ void QSGRenderer::preprocess()
     bool profileFrames = QSG_LOG_TIME_RENDERER().isDebugEnabled();
     if (profileFrames)
         preprocessTime = frameTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRendererFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRendererFrame,
+                              QQuickProfiler::SceneGraphRendererPreprocess);
 
     nodeUpdater()->updateStates(root);
 
     if (profileFrames)
         updatePassTime = frameTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRendererFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRendererFrame,
+                              QQuickProfiler::SceneGraphRendererUpdate);
 }
 
 void QSGRenderer::addNodesToPreprocess(QSGNode *node)
diff --git a/src/quick/scenegraph/qsgadaptationlayer.cpp b/src/quick/scenegraph/qsgadaptationlayer.cpp
index bf97133e97..f32829c2ea 100644
--- a/src/quick/scenegraph/qsgadaptationlayer.cpp
+++ b/src/quick/scenegraph/qsgadaptationlayer.cpp
@@ -179,7 +179,8 @@ void QSGDistanceFieldGlyphCache::update()
     int count = m_pendingGlyphs.size();
     if (profileFrames)
         renderTime = qsg_render_timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphAdaptationLayerFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphAdaptationLayerFrame,
+                              QQuickProfiler::SceneGraphAdaptationLayerGlyphRender);
 
     m_pendingGlyphs.reset();
 
@@ -200,6 +201,7 @@ void QSGDistanceFieldGlyphCache::update()
                 int((now - (renderTime / 1000000))));
     }
     Q_QUICK_SG_PROFILE_END_WITH_PAYLOAD(QQuickProfiler::SceneGraphAdaptationLayerFrame,
+                                        QQuickProfiler::SceneGraphAdaptationLayerGlyphStore,
                                         (qint64)count);
 }
 
diff --git a/src/quick/scenegraph/qsgrenderloop.cpp b/src/quick/scenegraph/qsgrenderloop.cpp
index 68947d3a3c..8fba301c4e 100644
--- a/src/quick/scenegraph/qsgrenderloop.cpp
+++ b/src/quick/scenegraph/qsgrenderloop.cpp
@@ -383,7 +383,8 @@ void QSGGuiThreadRenderLoop::renderWindow(QQuickWindow *window)
     if (profileFrames)
         polishTime = renderTimer.nsecsElapsed();
     Q_QUICK_SG_PROFILE_SWITCH(QQuickProfiler::SceneGraphPolishFrame,
-                              QQuickProfiler::SceneGraphRenderLoopFrame);
+                              QQuickProfiler::SceneGraphRenderLoopFrame,
+                              QQuickProfiler::SceneGraphPolishPolish);
 
     emit window->afterAnimating();
 
@@ -391,13 +392,15 @@ void QSGGuiThreadRenderLoop::renderWindow(QQuickWindow *window)
 
     if (profileFrames)
         syncTime = renderTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame,
+                              QQuickProfiler::SceneGraphRenderLoopSync);
 
     cd->renderSceneGraph(window->size());
 
     if (profileFrames)
         renderTime = renderTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame,
+                              QQuickProfiler::SceneGraphRenderLoopRender);
 
     if (data.grabOnly) {
         bool alpha = window->format().alphaBufferSize() > 0 && window->color().alpha() != 255;
@@ -414,7 +417,8 @@ void QSGGuiThreadRenderLoop::renderWindow(QQuickWindow *window)
     qint64 swapTime = 0;
     if (profileFrames)
         swapTime = renderTimer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphRenderLoopFrame);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphRenderLoopFrame,
+                           QQuickProfiler::SceneGraphRenderLoopSwap);
 
     if (QSG_LOG_TIME_RENDERLOOP().isDebugEnabled()) {
         static QTime lastFrameTime = QTime::currentTime();
diff --git a/src/quick/scenegraph/qsgthreadedrenderloop.cpp b/src/quick/scenegraph/qsgthreadedrenderloop.cpp
index ceb3caa53f..c9cc3b9fa0 100644
--- a/src/quick/scenegraph/qsgthreadedrenderloop.cpp
+++ b/src/quick/scenegraph/qsgthreadedrenderloop.cpp
@@ -591,7 +591,8 @@ void QSGRenderThread::syncAndRender()
     if (profileFrames)
         syncTime = threadTimer.nsecsElapsed();
 #endif
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame,
+                              QQuickProfiler::SceneGraphRenderLoopSync);
 
     if (!syncResultedInChanges && !repaintRequested && sgrc->isValid()) {
         qCDebug(QSG_LOG_RENDERLOOP) << QSG_RT_PAD << "- no changes, render aborted";
@@ -623,12 +624,14 @@ void QSGRenderThread::syncAndRender()
         d->renderSceneGraph(windowSize);
         if (profileFrames)
             renderTime = threadTimer.nsecsElapsed();
-        Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame);
+        Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphRenderLoopFrame,
+                                  QQuickProfiler::SceneGraphRenderLoopRender);
         if (!d->customRenderStage || !d->customRenderStage->swap())
             gl->swapBuffers(window);
         d->fireFrameSwapped();
     } else {
-        Q_QUICK_SG_PROFILE_SKIP(QQuickProfiler::SceneGraphRenderLoopFrame, 1);
+        Q_QUICK_SG_PROFILE_SKIP(QQuickProfiler::SceneGraphRenderLoopFrame,
+                                QQuickProfiler::SceneGraphRenderLoopSync, 1);
         qCDebug(QSG_LOG_RENDERLOOP) << QSG_RT_PAD << "- window not ready, skipping render";
     }
 
@@ -653,7 +656,8 @@ void QSGRenderThread::syncAndRender()
             int(threadTimer.elapsed() - renderTime / 1000000));
 
 
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphRenderLoopFrame);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphRenderLoopFrame,
+                           QQuickProfiler::SceneGraphRenderLoopSwap);
 }
 
 
@@ -1158,7 +1162,8 @@ void QSGThreadedRenderLoop::polishAndSync(Window *w, bool inExpose)
 
     if (profileFrames)
         polishTime = timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphPolishAndSync);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphPolishAndSync,
+                              QQuickProfiler::SceneGraphPolishAndSyncPolish);
 
     w->updateDuringSync = false;
 
@@ -1173,7 +1178,8 @@ void QSGThreadedRenderLoop::polishAndSync(Window *w, bool inExpose)
     qCDebug(QSG_LOG_RENDERLOOP) << "- wait for sync";
     if (profileFrames)
         waitTime = timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphPolishAndSync);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphPolishAndSync,
+                              QQuickProfiler::SceneGraphPolishAndSyncWait);
     w->thread->waitCondition.wait(&w->thread->mutex);
     m_lockedForSync = false;
     w->thread->mutex.unlock();
@@ -1181,7 +1187,8 @@ void QSGThreadedRenderLoop::polishAndSync(Window *w, bool inExpose)
 
     if (profileFrames)
         syncTime = timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphPolishAndSync);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphPolishAndSync,
+                              QQuickProfiler::SceneGraphPolishAndSyncSync);
 
     if (m_animation_timer == 0 && m_animation_driver->isRunning()) {
         qCDebug(QSG_LOG_RENDERLOOP) << "- advancing animations";
@@ -1202,7 +1209,8 @@ void QSGThreadedRenderLoop::polishAndSync(Window *w, bool inExpose)
             << ", animations=" << (timer.nsecsElapsed() - syncTime) / 1000000
             << " - (on Gui thread) " << window;
 
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphPolishAndSync);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphPolishAndSync,
+                           QQuickProfiler::SceneGraphPolishAndSyncAnimations);
 }
 
 bool QSGThreadedRenderLoop::event(QEvent *e)
diff --git a/src/quick/scenegraph/qsgwindowsrenderloop.cpp b/src/quick/scenegraph/qsgwindowsrenderloop.cpp
index 04a46bf929..510d65398d 100644
--- a/src/quick/scenegraph/qsgwindowsrenderloop.cpp
+++ b/src/quick/scenegraph/qsgwindowsrenderloop.cpp
@@ -61,9 +61,9 @@ static QElapsedTimer qsg_render_timer;
     if (QSG_LOG_TIME_RENDERLOOP().isDebugEnabled())  \
         sampleName = qsg_render_timer.nsecsElapsed(); \
 
-#define QSG_RENDER_TIMING_SAMPLE(frameType, sampleName) \
+#define QSG_RENDER_TIMING_SAMPLE(frameType, sampleName, position) \
     QSG_LOG_TIME_SAMPLE(sampleName) \
-    Q_QUICK_SG_PROFILE_RECORD(frameType);
+    Q_QUICK_SG_PROFILE_RECORD(frameType, position);
 
 
 QSGWindowsRenderLoop::QSGWindowsRenderLoop()
@@ -389,7 +389,7 @@ void QSGWindowsRenderLoop::render()
                 "animations ticked in %dms",
                 int((qsg_render_timer.nsecsElapsed() - time_start)/1000000));
 
-        Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphWindowsAnimations);
+        Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphWindowsAnimations, 1);
 
         // It is not given that animations triggered another maybeUpdate()
         // and thus another render pass, so to keep things running,
@@ -440,22 +440,26 @@ void QSGWindowsRenderLoop::renderWindow(QQuickWindow *window)
     d->polishItems();
     QSG_LOG_TIME_SAMPLE(time_polished);
     Q_QUICK_SG_PROFILE_SWITCH(QQuickProfiler::SceneGraphPolishFrame,
-                                QQuickProfiler::SceneGraphRenderLoopFrame);
+                              QQuickProfiler::SceneGraphRenderLoopFrame,
+                              QQuickProfiler::SceneGraphPolishPolish);
 
     emit window->afterAnimating();
 
     RLDEBUG(" - syncing");
     d->syncSceneGraph();
-    QSG_RENDER_TIMING_SAMPLE(QQuickProfiler::SceneGraphRenderLoopFrame, time_synced);
+    QSG_RENDER_TIMING_SAMPLE(QQuickProfiler::SceneGraphRenderLoopFrame, time_synced,
+                             QQuickProfiler::SceneGraphRenderLoopSync);
 
     RLDEBUG(" - rendering");
     d->renderSceneGraph(window->size());
-    QSG_RENDER_TIMING_SAMPLE(QQuickProfiler::SceneGraphRenderLoopFrame, time_rendered);
+    QSG_RENDER_TIMING_SAMPLE(QQuickProfiler::SceneGraphRenderLoopFrame, time_rendered,
+                             QQuickProfiler::SceneGraphRenderLoopRender);
 
     RLDEBUG(" - swapping");
     if (!d->customRenderStage || !d->customRenderStage->swap())
         m_gl->swapBuffers(window);
-    QSG_RENDER_TIMING_SAMPLE(QQuickProfiler::SceneGraphRenderLoopFrame, time_swapped);
+    QSG_RENDER_TIMING_SAMPLE(QQuickProfiler::SceneGraphRenderLoopFrame, time_swapped,
+                             QQuickProfiler::SceneGraphRenderLoopSwap);
 
     RLDEBUG(" - frameDone");
     d->fireFrameSwapped();
@@ -468,7 +472,8 @@ void QSGWindowsRenderLoop::renderWindow(QQuickWindow *window)
             << ", swap=" << (time_swapped - time_rendered) / 1000000
             << " - " << window;
 
-    Q_QUICK_SG_PROFILE_REPORT(QQuickProfiler::SceneGraphRenderLoopFrame);
+    Q_QUICK_SG_PROFILE_REPORT(QQuickProfiler::SceneGraphRenderLoopFrame,
+                              QQuickProfiler::SceneGraphRenderLoopSwap);
 }
 
 QT_END_NAMESPACE
diff --git a/src/quick/scenegraph/util/qsgatlastexture.cpp b/src/quick/scenegraph/util/qsgatlastexture.cpp
index e163191c6e..d26629900f 100644
--- a/src/quick/scenegraph/util/qsgatlastexture.cpp
+++ b/src/quick/scenegraph/util/qsgatlastexture.cpp
@@ -388,9 +388,12 @@ void Atlas::bind(QSGTexture::Filtering filtering)
         bool profileFrames = QSG_LOG_TIME_TEXTURE().isDebugEnabled();
         if (profileFrames)
             qsg_renderer_timer.start();
-        // Skip bind, convert, swizzle; they're irrelevant
+
         Q_QUICK_SG_PROFILE_START(QQuickProfiler::SceneGraphTexturePrepare);
-        Q_QUICK_SG_PROFILE_SKIP(QQuickProfiler::SceneGraphTexturePrepare, 3);
+
+        // Skip bind, convert, swizzle; they're irrelevant
+        Q_QUICK_SG_PROFILE_SKIP(QQuickProfiler::SceneGraphTexturePrepare,
+                                QQuickProfiler::SceneGraphTexturePrepareStart, 3);
 
         Texture *t = m_pending_uploads.at(i);
         if (m_externalFormat == GL_BGRA &&
@@ -408,10 +411,14 @@ void Atlas::bind(QSGTexture::Filtering filtering)
                                            << "ms (" << t->textureSize().width() << "x"
                                            << t->textureSize().height() << ")";
 
+        Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare,
+                                  QQuickProfiler::SceneGraphTexturePrepareUpload);
+
         // Skip mipmap; unused
-        Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare);
-        Q_QUICK_SG_PROFILE_SKIP(QQuickProfiler::SceneGraphTexturePrepare, 1);
-        Q_QUICK_SG_PROFILE_REPORT(QQuickProfiler::SceneGraphTexturePrepare);
+        Q_QUICK_SG_PROFILE_SKIP(QQuickProfiler::SceneGraphTexturePrepare,
+                                QQuickProfiler::SceneGraphTexturePrepareUpload, 1);
+        Q_QUICK_SG_PROFILE_REPORT(QQuickProfiler::SceneGraphTexturePrepare,
+                                  QQuickProfiler::SceneGraphTexturePrepareMipmap);
     }
 
     GLenum f = filtering == QSGTexture::Nearest ? GL_NEAREST : GL_LINEAR;
diff --git a/src/quick/scenegraph/util/qsgtexture.cpp b/src/quick/scenegraph/util/qsgtexture.cpp
index df9e569ca3..7625130dfe 100644
--- a/src/quick/scenegraph/util/qsgtexture.cpp
+++ b/src/quick/scenegraph/util/qsgtexture.cpp
@@ -646,7 +646,8 @@ void QSGPlainTexture::bind()
                     (int) qsg_renderer_timer.elapsed(),
                     m_texture_size.width(),
                     m_texture_size.height());
-            Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphTextureDeletion);
+            Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphTextureDeletion,
+                                   QQuickProfiler::SceneGraphTextureDeletionDelete);
         }
         m_texture_id = 0;
         m_texture_size = QSize();
@@ -662,7 +663,8 @@ void QSGPlainTexture::bind()
     qint64 bindTime = 0;
     if (profileFrames)
         bindTime = qsg_renderer_timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare,
+                              QQuickProfiler::SceneGraphTexturePrepareBind);
 
     // ### TODO: check for out-of-memory situations...
 
@@ -703,7 +705,8 @@ void QSGPlainTexture::bind()
     qint64 convertTime = 0;
     if (profileFrames)
         convertTime = qsg_renderer_timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare,
+                              QQuickProfiler::SceneGraphTexturePrepareConvert);
 
     updateBindOptions(m_dirty_bind_options);
 
@@ -746,14 +749,16 @@ void QSGPlainTexture::bind()
     qint64 swizzleTime = 0;
     if (profileFrames)
         swizzleTime = qsg_renderer_timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare,
+                              QQuickProfiler::SceneGraphTexturePrepareSwizzle);
 
     funcs->glTexImage2D(GL_TEXTURE_2D, 0, internalFormat, m_texture_size.width(), m_texture_size.height(), 0, externalFormat, GL_UNSIGNED_BYTE, tmp.constBits());
 
     qint64 uploadTime = 0;
     if (profileFrames)
         uploadTime = qsg_renderer_timer.nsecsElapsed();
-    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare);
+    Q_QUICK_SG_PROFILE_RECORD(QQuickProfiler::SceneGraphTexturePrepare,
+                              QQuickProfiler::SceneGraphTexturePrepareUpload);
 
     if (mipmapFiltering() != QSGTexture::None) {
         funcs->glGenerateMipmap(GL_TEXTURE_2D);
@@ -776,7 +781,8 @@ void QSGPlainTexture::bind()
                 int((mipmapTime - uploadTime)/1000000),
                 m_texture_size != m_image.size() ? " (scaled to GL_MAX_TEXTURE_SIZE)" : "");
     }
-    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphTexturePrepare);
+    Q_QUICK_SG_PROFILE_END(QQuickProfiler::SceneGraphTexturePrepare,
+                           QQuickProfiler::SceneGraphTexturePrepareMipmap);
 
     m_texture_rect = QRectF(0, 0, 1, 1);