aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorChristiaan Janssen <christiaan.janssen@digia.com>2013-04-17 16:46:12 +0200
committerThe Qt Project <gerrit-noreply@qt-project.org>2013-05-06 14:19:15 +0200
commit49ef011e33b9ef977679b3d30f883fccea0d8748 (patch)
tree96a17090cc17ab04796094a10809274e7a1f3944
parentf314fd4327167dd6af88f9b7050b34144d75241d (diff)
QmlProfiler: SceneGraph profiling
Change-Id: Ide71b330b13fc3816ed191bd9af84e0fce0d9587 Reviewed-by: Kai Koehne <kai.koehne@digia.com>
-rw-r--r--src/qml/debugger/qqmlprofilerservice.cpp110
-rw-r--r--src/qml/debugger/qqmlprofilerservice_p.h32
-rw-r--r--src/quick/scenegraph/coreapi/qsgrenderer.cpp52
-rw-r--r--src/quick/scenegraph/qsgadaptationlayer.cpp21
-rw-r--r--src/quick/scenegraph/qsgcontext.cpp10
-rw-r--r--src/quick/scenegraph/qsgrenderloop.cpp36
-rw-r--r--src/quick/scenegraph/qsgthreadedrenderloop.cpp77
-rw-r--r--src/quick/scenegraph/qsgwindowsrenderloop.cpp45
-rw-r--r--src/quick/scenegraph/util/qsgtexture.cpp58
-rw-r--r--tests/auto/qml/debugger/qqmlprofilerservice/data/scenegraphTest.qml18
-rw-r--r--tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp79
11 files changed, 418 insertions, 120 deletions
diff --git a/src/qml/debugger/qqmlprofilerservice.cpp b/src/qml/debugger/qqmlprofilerservice.cpp
index e016b2fdb5..963a861821 100644
--- a/src/qml/debugger/qqmlprofilerservice.cpp
+++ b/src/qml/debugger/qqmlprofilerservice.cpp
@@ -55,7 +55,7 @@ QT_BEGIN_NAMESPACE
// instance will be set, unset in constructor. Allows static methods to be inlined.
QQmlProfilerService *QQmlProfilerService::instance = 0;
Q_GLOBAL_STATIC(QQmlProfilerService, profilerInstance)
-
+bool QQmlProfilerService::enabled = false;
// convert to a QByteArray that can be sent to the debug client
// use of QDataStream can skew results
@@ -85,12 +85,37 @@ QByteArray QQmlProfilerData::toByteArray() const
default: break;
}
}
+ if (messageType == (int)QQmlProfilerService::SceneGraphFrame) {
+ switch (detailType) {
+ // RendererFrame: preprocessTime, updateTime, bindingTime, renderTime
+ case QQmlProfilerService::SceneGraphRendererFrame: ds << subtime_1 << subtime_2 << subtime_3 << subtime_4; break;
+ // AdaptationLayerFrame: glyphCount (which is an integer), glyphRenderTime, glyphStoreTime
+ case QQmlProfilerService::SceneGraphAdaptationLayerFrame: ds << (int)subtime_1 << subtime_2 << subtime_3; break;
+ // ContextFrame: compiling material time
+ case QQmlProfilerService::SceneGraphContextFrame: ds << subtime_1; break;
+ // RenderLoop: syncTime, renderTime, swapTime
+ case QQmlProfilerService::SceneGraphRenderLoopFrame: ds << subtime_1 << subtime_2 << subtime_3; break;
+ // TexturePrepare: bind, convert, swizzle, upload, mipmap
+ case QQmlProfilerService::SceneGraphTexturePrepare: ds << subtime_1 << subtime_2 << subtime_3 << subtime_4 << subtime_5; break;
+ // TextureDeletion: deletionTime
+ case QQmlProfilerService::SceneGraphTextureDeletion: ds << subtime_1; break;
+ // PolishAndSync: polishTime, waitTime, syncTime, animationsTime,
+ case QQmlProfilerService::SceneGraphPolishAndSync: ds << subtime_1 << subtime_2 << subtime_3 << subtime_4; break;
+ // WindowsRenderLoop: GL time, make current time, SceneGraph time
+ case QQmlProfilerService::SceneGraphWindowsRenderShow: ds << subtime_1 << subtime_2 << subtime_3; break;
+ // WindowsAnimations: update time
+ case QQmlProfilerService::SceneGraphWindowsAnimations: ds << subtime_1; break;
+ // WindowsRenderWindow: polish time, sync time, render time, swap time
+ case QQmlProfilerService::SceneGraphWindowsPolishFrame: ds << subtime_1; break;
+ default:break;
+ }
+ }
+
return data;
}
QQmlProfilerService::QQmlProfilerService()
- : QQmlDebugService(QStringLiteral("CanvasFrameRate"), 1),
- m_enabled(false)
+ : QQmlDebugService(QStringLiteral("CanvasFrameRate"), 1)
{
m_timer.start();
@@ -140,6 +165,11 @@ void QQmlProfilerService::animationFrame(qint64 delta)
profilerInstance()->animationFrameImpl(delta);
}
+void QQmlProfilerService::sceneGraphFrame(SceneGraphFrameType frameType, qint64 value1, qint64 value2, qint64 value3, qint64 value4, qint64 value5)
+{
+ profilerInstance()->sceneGraphFrameImpl(frameType, value1, value2, value3, value4, value5);
+}
+
void QQmlProfilerService::sendProfilingData()
{
profilerInstance()->sendMessages();
@@ -169,81 +199,89 @@ bool QQmlProfilerService::stopProfilingImpl()
void QQmlProfilerService::sendStartedProfilingMessageImpl()
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData ed = {m_timer.nsecsElapsed(), (int)Event, (int)StartTrace,
- QString(), -1, -1, 0, 0, 0};
+ QString(), -1, -1, 0, 0, 0,
+ 0, 0, 0, 0, 0};
QQmlDebugService::sendMessage(ed.toByteArray());
}
void QQmlProfilerService::addEventImpl(EventType event)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData ed = {m_timer.nsecsElapsed(), (int)Event, (int)event,
- QString(), -1, -1, 0, 0, 0};
+ QString(), -1, -1, 0, 0, 0,
+ 0, 0, 0, 0, 0};
processMessage(ed);
}
void QQmlProfilerService::startRange(RangeType range, BindingType bindingType)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)RangeStart, (int)range,
- QString(), -1, -1, 0, 0, (int)bindingType};
+ QString(), -1, -1, 0, 0, (int)bindingType,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
void QQmlProfilerService::rangeData(RangeType range, const QString &rData)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)RangeData, (int)range,
- rData, -1, -1, 0, 0, 0};
+ rData, -1, -1, 0, 0, 0,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
void QQmlProfilerService::rangeData(RangeType range, const QUrl &rData)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)RangeData, (int)range,
- rData.toString(), -1, -1, 0, 0, 0};
+ rData.toString(), -1, -1, 0, 0, 0,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
void QQmlProfilerService::rangeLocation(RangeType range, const QString &fileName, int line, int column)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)RangeLocation, (int)range,
- fileName, line, column, 0, 0, 0};
+ fileName, line, column, 0, 0, 0,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
void QQmlProfilerService::rangeLocation(RangeType range, const QUrl &fileName, int line, int column)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)RangeLocation, (int)range,
- fileName.toString(), line, column, 0, 0, 0};
+ fileName.toString(), line, column, 0, 0, 0,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
void QQmlProfilerService::endRange(RangeType range)
{
- if (!QQmlDebugService::isDebuggingEnabled() || !m_enabled)
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
return;
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)RangeEnd, (int)range,
- QString(), -1, -1, 0, 0, 0};
+ QString(), -1, -1, 0, 0, 0,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
@@ -251,7 +289,8 @@ void QQmlProfilerService::pixmapEventImpl(PixmapEventType eventType, const QUrl
{
// assuming enabled checked by caller
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)PixmapCacheEvent, (int)eventType,
- url.toString(), -1, -1, -1, -1, -1};
+ url.toString(), -1, -1, -1, -1, -1,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
@@ -259,7 +298,8 @@ void QQmlProfilerService::pixmapEventImpl(PixmapEventType eventType, const QUrl
{
// assuming enabled checked by caller
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)PixmapCacheEvent, (int)eventType,
- url.toString(), width, height, -1, -1, -1};
+ url.toString(), width, height, -1, -1, -1,
+ 0, 0, 0, 0, 0};
processMessage(rd);
}
@@ -267,14 +307,28 @@ void QQmlProfilerService::pixmapEventImpl(PixmapEventType eventType, const QUrl
{
// assuming enabled checked by caller
QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)PixmapCacheEvent, (int)eventType,
- url.toString(), -1, -1, -1, count, -1};
+ url.toString(), -1, -1, -1, count, -1,
+ 0, 0, 0, 0, 0};
+ processMessage(rd);
+}
+
+void QQmlProfilerService::sceneGraphFrameImpl(SceneGraphFrameType frameType, qint64 value1, qint64 value2, qint64 value3, qint64 value4, qint64 value5)
+{
+ if (!QQmlDebugService::isDebuggingEnabled() || !enabled)
+ return;
+
+ // because I already have some space to store ints in the struct, I'll use it to store the frame data
+ // even though the field names do not match
+ QQmlProfilerData rd = {m_timer.nsecsElapsed(), (int)SceneGraphFrame, (int)frameType, QString(),
+ -1, -1, -1, -1, -1,
+ value1, value2, value3, value4, value5};
processMessage(rd);
}
void QQmlProfilerService::animationFrameImpl(qint64 delta)
{
Q_ASSERT(QQmlDebugService::isDebuggingEnabled());
- if (!m_enabled)
+ if (!enabled)
return;
int animCount = QUnifiedTimer::instance()->runningAnimationCount();
@@ -283,7 +337,8 @@ void QQmlProfilerService::animationFrameImpl(qint64 delta)
// trim fps to integer
int fps = 1000 / delta;
QQmlProfilerData ed = {m_timer.nsecsElapsed(), (int)Event, (int)AnimationFrame,
- QString(), -1, -1, fps, animCount, 0};
+ QString(), -1, -1, fps, animCount, 0,
+ 0, 0, 0, 0, 0};
processMessage(ed);
}
}
@@ -300,12 +355,12 @@ void QQmlProfilerService::processMessage(const QQmlProfilerData &message)
bool QQmlProfilerService::profilingEnabled()
{
- return m_enabled;
+ return enabled;
}
void QQmlProfilerService::setProfilingEnabled(bool enable)
{
- m_enabled = enable;
+ enabled = enable;
}
/*
@@ -314,6 +369,7 @@ void QQmlProfilerService::setProfilingEnabled(bool enable)
void QQmlProfilerService::sendMessages()
{
QMutexLocker locker(&m_dataMutex);
+
QList<QByteArray> messages;
for (int i = 0; i < m_data.count(); ++i)
messages << m_data.at(i).toByteArray();
@@ -336,7 +392,7 @@ void QQmlProfilerService::stateAboutToBeChanged(QQmlDebugService::State newState
return;
if (state() == Enabled
- && m_enabled) {
+ && enabled) {
stopProfilingImpl();
sendMessages();
}
diff --git a/src/qml/debugger/qqmlprofilerservice_p.h b/src/qml/debugger/qqmlprofilerservice_p.h
index 30eb2ebbf4..fb08a30c6a 100644
--- a/src/qml/debugger/qqmlprofilerservice_p.h
+++ b/src/qml/debugger/qqmlprofilerservice_p.h
@@ -80,6 +80,12 @@ struct Q_AUTOTEST_EXPORT QQmlProfilerData
int animationcount; //used by animation events, also as "cache/reference count" for pixmaps
int bindingType;
+ qint64 subtime_1;
+ qint64 subtime_2;
+ qint64 subtime_3;
+ qint64 subtime_4;
+ qint64 subtime_5;
+
QByteArray toByteArray() const;
};
@@ -100,6 +106,7 @@ public:
RangeEnd,
Complete, // end of transmission
PixmapCacheEvent,
+ SceneGraphFrame,
MaximumMessage
};
@@ -144,14 +151,32 @@ public:
MaximumPixmapEventType
};
+ enum SceneGraphFrameType {
+ SceneGraphRendererFrame,
+ SceneGraphAdaptationLayerFrame,
+ SceneGraphContextFrame,
+ SceneGraphRenderLoopFrame,
+ SceneGraphTexturePrepare,
+ SceneGraphTextureDeletion,
+ SceneGraphPolishAndSync,
+ SceneGraphWindowsRenderShow,
+ SceneGraphWindowsAnimations,
+ SceneGraphWindowsPolishFrame,
+
+ MaximumSceneGraphFrameType
+ };
+
static void initialize();
static bool startProfiling();
static bool stopProfiling();
static void sendStartedProfilingMessage();
+ static bool profilingEnabled();
+
static void addEvent(EventType);
static void animationFrame(qint64);
+ static void sceneGraphFrame(SceneGraphFrameType frameType, qint64 value1, qint64 value2 = -1, qint64 value3 = -1, qint64 value4 = -1, qint64 value5 = -1);
static void sendProfilingData();
QQmlProfilerService();
@@ -180,14 +205,17 @@ private:
void pixmapEventImpl(PixmapEventType eventType, const QUrl &url, int width, int height);
void pixmapEventImpl(PixmapEventType eventType, const QUrl &url, int count);
- bool profilingEnabled();
+ void sceneGraphFrameImpl(SceneGraphFrameType frameType, qint64 value1, qint64 value2, qint64 value3, qint64 value4, qint64 value5);
+
+
void setProfilingEnabled(bool enable);
void sendMessages();
void processMessage(const QQmlProfilerData &);
+public:
+ static bool enabled;
private:
QElapsedTimer m_timer;
- bool m_enabled;
QVector<QQmlProfilerData> m_data;
QMutex m_dataMutex;
QMutex m_initializeMutex;
diff --git a/src/quick/scenegraph/coreapi/qsgrenderer.cpp b/src/quick/scenegraph/coreapi/qsgrenderer.cpp
index b46d45be57..805cfaad0d 100644
--- a/src/quick/scenegraph/coreapi/qsgrenderer.cpp
+++ b/src/quick/scenegraph/coreapi/qsgrenderer.cpp
@@ -53,6 +53,8 @@
#include <qdatetime.h>
+#include <private/qqmlprofilerservice_p.h>
+
QT_BEGIN_NAMESPACE
//#define RENDERER_DEBUG
@@ -62,9 +64,9 @@ QT_BEGIN_NAMESPACE
#ifndef QSG_NO_RENDER_TIMING
static bool qsg_render_timing = !qgetenv("QSG_RENDER_TIMING").isEmpty();
-static QTime frameTimer;
-static int preprocessTime;
-static int updatePassTime;
+static QElapsedTimer frameTimer;
+static qint64 preprocessTime;
+static qint64 updatePassTime;
#endif
void QSGBindable::clear(QSGRenderer::ClearMode mode) const
@@ -238,10 +240,11 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
+ bool profileFrames = qsg_render_timing || QQmlProfilerService::enabled;
+ if (profileFrames)
frameTimer.start();
- int bindTime = 0;
- int renderTime = 0;
+ qint64 bindTime = 0;
+ qint64 renderTime = 0;
#endif
m_bindable = &bindable;
@@ -249,8 +252,8 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
bindable.bind();
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- bindTime = frameTimer.elapsed();
+ if (profileFrames)
+ bindTime = frameTimer.nsecsElapsed();
#endif
#ifndef QT_NO_DEBUG
@@ -270,8 +273,8 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
render();
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- renderTime = frameTimer.elapsed();
+ if (profileFrames)
+ renderTime = frameTimer.nsecsElapsed();
#endif
glDisable(GL_SCISSOR_TEST);
@@ -292,12 +295,22 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
#ifndef QSG_NO_RENDER_TIMING
if (qsg_render_timing) {
printf(" - Breakdown of render time: preprocess=%d, updates=%d, binding=%d, render=%d, total=%d\n",
- preprocessTime,
- updatePassTime - preprocessTime,
- bindTime - updatePassTime,
- renderTime - bindTime,
- renderTime);
+ int(preprocessTime / 1000000),
+ int((updatePassTime - preprocessTime) / 1000000),
+ int((bindTime - updatePassTime) / 1000000),
+ int((renderTime - bindTime) / 1000000),
+ int(renderTime / 1000000));
+ }
+
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphRendererFrame,
+ preprocessTime,
+ updatePassTime - preprocessTime,
+ bindTime - updatePassTime,
+ renderTime - bindTime);
}
+
#endif
}
@@ -380,16 +393,17 @@ void QSGRenderer::preprocess()
}
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- preprocessTime = frameTimer.elapsed();
+ bool profileFrames = qsg_render_timing || QQmlProfilerService::enabled;
+ if (profileFrames)
+ preprocessTime = frameTimer.nsecsElapsed();
#endif
nodeUpdater()->setToplevelOpacity(context()->renderAlpha());
nodeUpdater()->updateStates(m_root_node);
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- updatePassTime = frameTimer.elapsed();
+ if (profileFrames)
+ updatePassTime = frameTimer.nsecsElapsed();
#endif
}
diff --git a/src/quick/scenegraph/qsgadaptationlayer.cpp b/src/quick/scenegraph/qsgadaptationlayer.cpp
index 1d534e3563..3536975e94 100644
--- a/src/quick/scenegraph/qsgadaptationlayer.cpp
+++ b/src/quick/scenegraph/qsgadaptationlayer.cpp
@@ -48,6 +48,7 @@
#include <QtGui/qguiapplication.h>
#include <qdir.h>
+#include <private/qqmlprofilerservice_p.h>
#include <QElapsedTimer>
QT_BEGIN_NAMESPACE
@@ -162,7 +163,8 @@ void QSGDistanceFieldGlyphCache::update()
return;
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
+ bool profileFrames = qsg_render_timing || QQmlProfilerService::enabled;
+ if (profileFrames)
qsg_render_timer.start();
#endif
@@ -176,10 +178,10 @@ void QSGDistanceFieldGlyphCache::update()
}
#ifndef QSG_NO_RENDER_TIMING
- int renderTime = 0;
+ qint64 renderTime = 0;
int count = m_pendingGlyphs.size();
- if (qsg_render_timing)
- renderTime = qsg_render_timer.elapsed();
+ if (profileFrames)
+ renderTime = qsg_render_timer.nsecsElapsed();
#endif
m_pendingGlyphs.reset();
@@ -190,11 +192,18 @@ void QSGDistanceFieldGlyphCache::update()
if (qsg_render_timing) {
printf(" - glyphs: count=%d, render=%d, store=%d, total=%d\n",
count,
- renderTime,
- (int) qsg_render_timer.elapsed() - renderTime,
+ int(renderTime/1000000),
+ (int) qsg_render_timer.elapsed() - int(renderTime/1000000),
(int) qsg_render_timer.elapsed());
}
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphAdaptationLayerFrame,
+ count,
+ renderTime,
+ qsg_render_timer.nsecsElapsed() - renderTime);
+ }
#endif
}
diff --git a/src/quick/scenegraph/qsgcontext.cpp b/src/quick/scenegraph/qsgcontext.cpp
index 5d894e5236..14f0fabbdd 100644
--- a/src/quick/scenegraph/qsgcontext.cpp
+++ b/src/quick/scenegraph/qsgcontext.cpp
@@ -67,6 +67,8 @@
#include <private/qobject_p.h>
#include <qmutex.h>
+#include <private/qqmlprofilerservice_p.h>
+
DEFINE_BOOL_CONFIG_OPTION(qmlFlashMode, QML_FLASH_MODE)
DEFINE_BOOL_CONFIG_OPTION(qmlTranslucentMode, QML_TRANSLUCENT_MODE)
DEFINE_BOOL_CONFIG_OPTION(qmlDisableDistanceField, QML_DISABLE_DISTANCEFIELD)
@@ -482,7 +484,7 @@ QSGMaterialShader *QSGContext::prepareMaterial(QSGMaterial *material)
return shader;
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
+ if (qsg_render_timing || QQmlProfilerService::enabled)
qsg_renderer_timer.start();
#endif
@@ -494,6 +496,12 @@ QSGMaterialShader *QSGContext::prepareMaterial(QSGMaterial *material)
#ifndef QSG_NO_RENDER_TIMING
if (qsg_render_timing)
printf(" - compiling material: %dms\n", (int) qsg_renderer_timer.elapsed());
+
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphContextFrame,
+ qsg_renderer_timer.nsecsElapsed());
+ }
#endif
return shader;
diff --git a/src/quick/scenegraph/qsgrenderloop.cpp b/src/quick/scenegraph/qsgrenderloop.cpp
index f71ccea294..3a608a911d 100644
--- a/src/quick/scenegraph/qsgrenderloop.cpp
+++ b/src/quick/scenegraph/qsgrenderloop.cpp
@@ -56,6 +56,7 @@
#include <QtQuick/QQuickWindow>
#include <QtQuick/private/qquickwindow_p.h>
#include <QtQuick/private/qsgcontext_p.h>
+#include <private/qqmlprofilerservice_p.h>
QT_BEGIN_NAMESPACE
@@ -273,20 +274,21 @@ void QSGGuiThreadRenderLoop::renderWindow(QQuickWindow *window)
QQuickWindowPrivate *cd = QQuickWindowPrivate::get(window);
cd->polishItems();
- int renderTime = 0, syncTime = 0;
- QTime renderTimer;
- if (qsg_render_timing())
+ qint64 renderTime = 0, syncTime = 0;
+ QElapsedTimer renderTimer;
+ bool profileFrames = qsg_render_timing() || QQmlProfilerService::enabled;
+ if (profileFrames)
renderTimer.start();
cd->syncSceneGraph();
- if (qsg_render_timing())
- syncTime = renderTimer.elapsed();
+ if (profileFrames)
+ syncTime = renderTimer.nsecsElapsed();
cd->renderSceneGraph(window->size());
- if (qsg_render_timing())
- renderTime = renderTimer.elapsed() - syncTime;
+ if (profileFrames)
+ renderTime = renderTimer.nsecsElapsed() - syncTime;
if (data.grabOnly) {
grabContent = qt_gl_read_framebuffer(window->size(), false, false);
@@ -298,17 +300,29 @@ void QSGGuiThreadRenderLoop::renderWindow(QQuickWindow *window)
cd->fireFrameSwapped();
}
+ qint64 swapTime = 0;
+ if (profileFrames) {
+ swapTime = renderTimer.nsecsElapsed() - renderTime - syncTime;
+ }
+
if (qsg_render_timing()) {
static QTime lastFrameTime = QTime::currentTime();
- const int swapTime = renderTimer.elapsed() - renderTime - syncTime;
- qDebug() << "- Breakdown of frame time; sync:" << syncTime
- << "ms render:" << renderTime << "ms swap:" << swapTime
- << "ms total:" << swapTime + renderTime + syncTime
+ qDebug() << "- Breakdown of frame time; sync:" << syncTime/1000000
+ << "ms render:" << renderTime/1000000 << "ms swap:" << swapTime/1000000
+ << "ms total:" << (swapTime + renderTime + syncTime)/1000000
<< "ms time since last frame:" << (lastFrameTime.msecsTo(QTime::currentTime()))
<< "ms";
lastFrameTime = QTime::currentTime();
}
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphRenderLoopFrame,
+ syncTime,
+ renderTime,
+ swapTime);
+ }
+
// Might have been set during syncSceneGraph()
if (data.updatePending)
maybeUpdate(window);
diff --git a/src/quick/scenegraph/qsgthreadedrenderloop.cpp b/src/quick/scenegraph/qsgthreadedrenderloop.cpp
index de1e2517db..c4a9328ceb 100644
--- a/src/quick/scenegraph/qsgthreadedrenderloop.cpp
+++ b/src/quick/scenegraph/qsgthreadedrenderloop.cpp
@@ -55,6 +55,8 @@
#include "qsgthreadedrenderloop_p.h"
+#include <private/qqmlprofilerservice_p.h>
+
/*
Overall design:
@@ -138,10 +140,10 @@ static inline int qsgrl_animation_interval() {
#ifndef QSG_NO_RENDER_TIMING
static bool qsg_render_timing = !qgetenv("QSG_RENDER_TIMING").isEmpty();
-static QTime threadTimer;
-static int syncTime;
-static int renderTime;
-static int sinceLastTime;
+static QElapsedTimer threadTimer;
+static qint64 syncTime;
+static qint64 renderTime;
+static qint64 sinceLastTime;
#endif
extern Q_GUI_EXPORT QImage qt_gl_read_framebuffer(const QSize &size, bool alpha_format, bool include_alpha);
@@ -545,8 +547,11 @@ void QSGRenderThread::sync()
void QSGRenderThread::syncAndRender()
{
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- sinceLastTime = threadTimer.restart();
+ bool profileFrames = qsg_render_timing || QQmlProfilerService::enabled;
+ if (profileFrames) {
+ sinceLastTime = threadTimer.nsecsElapsed();
+ threadTimer.start();
+ }
#endif
QElapsedTimer waitTimer;
waitTimer.start();
@@ -573,8 +578,8 @@ void QSGRenderThread::syncAndRender()
}
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- syncTime = threadTimer.elapsed();
+ if (profileFrames)
+ syncTime = threadTimer.nsecsElapsed();
#endif
RLDEBUG(" Render: - rendering starting");
@@ -588,8 +593,8 @@ void QSGRenderThread::syncAndRender()
gl->makeCurrent(w.window);
d->renderSceneGraph(w.size);
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing && i == 0)
- renderTime = threadTimer.elapsed();
+ if (profileFrames && i == 0)
+ renderTime = threadTimer.nsecsElapsed();
#endif
gl->swapBuffers(w.window);
d->fireFrameSwapped();
@@ -599,10 +604,18 @@ void QSGRenderThread::syncAndRender()
#ifndef QSG_NO_RENDER_TIMING
if (qsg_render_timing)
qDebug("window Time: sinceLast=%d, sync=%d, first render=%d, after final swap=%d",
- sinceLastTime,
- syncTime,
- renderTime - syncTime,
- threadTimer.elapsed() - renderTime);
+ int(sinceLastTime/1000000),
+ int(syncTime/1000000),
+ int((renderTime - syncTime)/1000000),
+ int(threadTimer.elapsed() - renderTime/1000000));
+
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphRenderLoopFrame,
+ syncTime,
+ renderTime - syncTime,
+ threadTimer.nsecsElapsed() - renderTime);
+ }
#endif
}
@@ -950,10 +963,11 @@ void QSGThreadedRenderLoop::polishAndSync()
#ifndef QSG_NO_RENDER_TIMING
QElapsedTimer timer;
- int polishTime = 0;
- int waitTime = 0;
- int syncTime;
- if (qsg_render_timing)
+ qint64 polishTime = 0;
+ qint64 waitTime = 0;
+ qint64 syncTime = 0;
+ bool profileFrames = qsg_render_timing || QQmlProfilerService::enabled;
+ if (profileFrames)
timer.start();
#endif
@@ -964,8 +978,8 @@ void QSGThreadedRenderLoop::polishAndSync()
d->polishItems();
}
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- polishTime = timer.elapsed();
+ if (profileFrames)
+ polishTime = timer.nsecsElapsed();
#endif
m_sync_triggered_update = false;
@@ -977,8 +991,8 @@ void QSGThreadedRenderLoop::polishAndSync()
RLDEBUG("GUI: - wait for sync...");
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- waitTime = timer.elapsed();
+ if (profileFrames)
+ waitTime = timer.nsecsElapsed();
#endif
m_thread->waitCondition.wait(&m_thread->mutex);
m_thread->guiIsLocked = false;
@@ -986,8 +1000,8 @@ void QSGThreadedRenderLoop::polishAndSync()
RLDEBUG("GUI: - unlocked after sync...");
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
- syncTime = timer.elapsed();
+ if (profileFrames)
+ syncTime = timer.nsecsElapsed();
#endif
killTimer(m_update_timer);
@@ -1006,7 +1020,20 @@ void QSGThreadedRenderLoop::polishAndSync()
#ifndef QSG_NO_RENDER_TIMING
if (qsg_render_timing)
- qDebug(" - polish=%d, wait=%d, sync=%d -- animations=%d", polishTime, waitTime - polishTime, syncTime - waitTime, int(timer.elapsed() - syncTime));
+ qDebug(" - polish=%d, wait=%d, sync=%d -- animations=%d",
+ int(polishTime/1000000),
+ int((waitTime - polishTime)/1000000),
+ int((syncTime - waitTime)/1000000),
+ int((timer.nsecsElapsed() - syncTime)/1000000));
+
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphPolishAndSync,
+ polishTime,
+ waitTime - polishTime,
+ syncTime - waitTime,
+ timer.elapsed() - syncTime);
+ }
#endif
}
diff --git a/src/quick/scenegraph/qsgwindowsrenderloop.cpp b/src/quick/scenegraph/qsgwindowsrenderloop.cpp
index 3e21af6ac0..ce43ccf531 100644
--- a/src/quick/scenegraph/qsgwindowsrenderloop.cpp
+++ b/src/quick/scenegraph/qsgwindowsrenderloop.cpp
@@ -51,6 +51,8 @@
#include <QtQuick/QQuickWindow>
+#include <private/qqmlprofilerservice_p.h>
+
QT_BEGIN_NAMESPACE
extern Q_GUI_EXPORT QImage qt_gl_read_framebuffer(const QSize &size, bool alpha_format, bool include_alpha);
@@ -67,7 +69,7 @@ static QElapsedTimer qsg_debug_timer;
#ifndef QSG_NO_RENDER_TIMING
static bool qsg_render_timing = !qgetenv("QSG_RENDER_TIMING").isEmpty();
static QElapsedTimer qsg_render_timer;
-#define QSG_RENDER_TIMING_SAMPLE(sampleName) int sampleName = 0; if (qsg_render_timing) sampleName = qsg_render_timer.elapsed()
+#define QSG_RENDER_TIMING_SAMPLE(sampleName) qint64 sampleName = 0; if (qsg_render_timing || QQmlProfilerService::enabled) sampleName = qsg_render_timer.nsecsElapsed()
#else
#define QSG_RENDER_TIMING_SAMPLE(sampleName)
#endif
@@ -174,9 +176,16 @@ void QSGWindowsRenderLoop::show(QQuickWindow *window)
#ifndef QSG_NO_RENDER_TIMING
if (qsg_render_timing) {
qDebug("WindowsRenderLoop: GL=%d ms, makeCurrent=%d ms, SG=%d ms",
- int(time_created - time_start),
- int(time_current - time_created),
- int(qsg_render_timer.elapsed() - time_current));
+ int((time_created - time_start)/1000000),
+ int((time_current - time_created)/1000000),
+ int((qsg_render_timer.nsecsElapsed() - time_current)/1000000));
+ }
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphWindowsRenderShow,
+ time_created - time_start,
+ time_current - time_created,
+ qsg_render_timer.nsecsElapsed() - time_current);
}
#endif
@@ -368,7 +377,12 @@ void QSGWindowsRenderLoop::render()
#ifndef QSG_NO_RENDER_TIMING
if (qsg_render_timing) {
qDebug("WindowsRenderLoop: animations=%d ms",
- int(qsg_render_timer.elapsed() - time_start));
+ int((qsg_render_timer.nsecsElapsed() - time_start)/1000000));
+ }
+ if (QQmlProfilerService::Enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphWindowsAnimations,
+ qsg_render_timer.nsecsElapsed() - time_start);
}
#endif
@@ -424,10 +438,23 @@ void QSGWindowsRenderLoop::renderWindow(QQuickWindow *window)
qDebug("WindowsRenderLoop(t=%d): window=%p, polish=%d ms, sync=%d ms, render=%d ms, swap=%d ms",
int(qsg_render_timer.elapsed()),
window,
- int(time_polished - time_start),
- int(time_synced - time_polished),
- int(time_rendered - time_synced),
- int(time_swapped - time_rendered));
+ int((time_polished - time_start)/1000000),
+ int((time_synced - time_polished)/1000000),
+ int((time_rendered - time_synced)/1000000),
+ int((time_swapped - time_rendered)/1000000));
+ }
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphWindowsPolishFrame,
+ time_polished - time_start
+ );
+
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphRenderLoopFrame,
+ time_synced - time_polished,
+ time_rendered - time_synced,
+ time_swapped - time_rendered
+ );
}
#endif
}
diff --git a/src/quick/scenegraph/util/qsgtexture.cpp b/src/quick/scenegraph/util/qsgtexture.cpp
index ad98fe9d47..a104e4af2f 100644
--- a/src/quick/scenegraph/util/qsgtexture.cpp
+++ b/src/quick/scenegraph/util/qsgtexture.cpp
@@ -614,7 +614,8 @@ void QSGPlainTexture::bind()
m_dirty_texture = false;
#ifndef QSG_NO_RENDER_TIMING
- if (qsg_render_timing)
+ bool profileFrames = qsg_render_timing || QQmlProfilerService::enabled;
+ if (profileFrames)
qsg_renderer_timer.start();
#endif
@@ -628,6 +629,11 @@ void QSGPlainTexture::bind()
m_texture_size.width(),
m_texture_size.height());
}
+ if (QQmlProfilerService::enabled) {
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphTextureDeletion,
+ qsg_renderer_timer.nsecsElapsed());
+ }
#endif
}
m_texture_id = 0;
@@ -645,9 +651,9 @@ void QSGPlainTexture::bind()
glBindTexture(GL_TEXTURE_2D, m_texture_id);
#ifndef QSG_NO_RENDER_TIMING
- int bindTime = 0;
- if (qsg_render_timing)
- bindTime = qsg_renderer_timer.elapsed();
+ qint64 bindTime = 0;
+ if (profileFrames)
+ bindTime = qsg_renderer_timer.nsecsElapsed();
#endif
// ### TODO: check for out-of-memory situations...
@@ -659,9 +665,9 @@ void QSGPlainTexture::bind()
: m_image.convertToFormat(QImage::Format_ARGB32_Premultiplied);
#ifndef QSG_NO_RENDER_TIMING
- int convertTime = 0;
- if (qsg_render_timing)
- convertTime = qsg_renderer_timer.elapsed();
+ qint64 convertTime = 0;
+ if (profileFrames)
+ convertTime = qsg_renderer_timer.nsecsElapsed();
#endif
updateBindOptions(m_dirty_bind_options);
@@ -684,16 +690,16 @@ void QSGPlainTexture::bind()
}
#ifndef QSG_NO_RENDER_TIMING
- int swizzleTime = 0;
- if (qsg_render_timing)
- swizzleTime = qsg_renderer_timer.elapsed();
+ qint64 swizzleTime = 0;
+ if (profileFrames)
+ swizzleTime = qsg_renderer_timer.nsecsElapsed();
#endif
glTexImage2D(GL_TEXTURE_2D, 0, internalFormat, w, h, 0, externalFormat, GL_UNSIGNED_BYTE, tmp.constBits());
#ifndef QSG_NO_RENDER_TIMING
- int uploadTime = 0;
- if (qsg_render_timing)
- uploadTime = qsg_renderer_timer.elapsed();
+ qint64 uploadTime = 0;
+ if (profileFrames)
+ uploadTime = qsg_renderer_timer.nsecsElapsed();
#endif
@@ -704,23 +710,35 @@ void QSGPlainTexture::bind()
}
#ifndef QSG_NO_RENDER_TIMING
- int mipmapTime = 0;
+ qint64 mipmapTime = 0;
if (qsg_render_timing) {
- mipmapTime = qsg_renderer_timer.elapsed();
+ mipmapTime = qsg_renderer_timer.nsecsElapsed();
printf(" - plaintexture(%dx%d) bind=%d, convert=%d, swizzle=%d (%s->%s), upload=%d, mipmap=%d, total=%d\n",
m_texture_size.width(), m_texture_size.height(),
- bindTime,
- convertTime - bindTime,
- swizzleTime - convertTime,
+ int(bindTime/1000000),
+ int((convertTime - bindTime)/1000000),
+ int((swizzleTime - convertTime)/1000000),
externalFormat == GL_BGRA ? "BGRA" : "RGBA",
internalFormat == GL_BGRA ? "BGRA" : "RGBA",
- uploadTime - swizzleTime,
- mipmapTime - uploadTime,
+ int((uploadTime - swizzleTime)/1000000),
+ int((mipmapTime - uploadTime)/1000000),
(int) qsg_renderer_timer.elapsed());
}
+ if (QQmlProfilerService::enabled) {
+ mipmapTime = qsg_renderer_timer.nsecsElapsed();
+
+ QQmlProfilerService::sceneGraphFrame(
+ QQmlProfilerService::SceneGraphTexturePrepare,
+ bindTime,
+ convertTime - bindTime,
+ swizzleTime - convertTime,
+ uploadTime - swizzleTime,
+ mipmapTime - uploadTime);
+ }
+
#endif
diff --git a/tests/auto/qml/debugger/qqmlprofilerservice/data/scenegraphTest.qml b/tests/auto/qml/debugger/qqmlprofilerservice/data/scenegraphTest.qml
new file mode 100644
index 0000000000..dd9d053296
--- /dev/null
+++ b/tests/auto/qml/debugger/qqmlprofilerservice/data/scenegraphTest.qml
@@ -0,0 +1,18 @@
+import QtQuick 2.0
+
+Rectangle {
+ Rectangle {
+ width: 10
+ height: 10
+ color: "blue"
+ }
+
+ Component.onCompleted: timer.start();
+
+ Timer {
+ id: timer
+ interval: 100 // 100 ms, enough for at least one frame
+ running: false
+ onTriggered: console.log("tick")
+ }
+}
diff --git a/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp b/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
index 8ad4f52b91..21fc48117f 100644
--- a/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
+++ b/tests/auto/qml/debugger/qqmlprofilerservice/tst_qqmlprofilerservice.cpp
@@ -78,6 +78,7 @@ public:
RangeEnd,
Complete, // end of transmission
PixmapCacheEvent,
+ SceneGraphFrame,
MaximumMessage
};
@@ -114,6 +115,21 @@ public:
MaximumPixmapEventType
};
+ enum SceneGraphFrameType {
+ SceneGraphRendererFrame,
+ SceneGraphAdaptationLayerFrame,
+ SceneGraphContextFrame,
+ SceneGraphRenderLoopFrame,
+ SceneGraphTexturePrepare,
+ SceneGraphTextureDeletion,
+ SceneGraphPolishAndSync,
+ SceneGraphWindowsRenderShow,
+ SceneGraphWindowsAnimations,
+ SceneGraphWindowsPolishFrame,
+
+ MaximumSceneGraphFrameType
+ };
+
QQmlProfilerClient(QQmlDebugConnection *connection)
: QQmlDebugClient(QLatin1String("CanvasFrameRate"), connection)
{
@@ -147,6 +163,7 @@ public:
{
}
+
private:
QQmlDebugProcess *m_process;
QQmlDebugConnection *m_connection;
@@ -161,6 +178,7 @@ private slots:
void blockingConnectWithTraceDisabled();
void nonBlockingConnect();
void pixmapCacheData();
+ void scenegraphData();
void profileOnExit();
};
@@ -242,6 +260,34 @@ void QQmlProfilerClient::messageReceived(const QByteArray &message)
stream >> data.animationcount;
break;
}
+ case QQmlProfilerClient::SceneGraphFrame: {
+ stream >> data.detailType;
+ qint64 subtime_1, subtime_2, subtime_3, subtime_4, subtime_5;
+ int glyphCount;
+ switch (data.detailType) {
+ // RendererFrame: preprocessTime, updateTime, bindingTime, renderTime
+ case QQmlProfilerClient::SceneGraphRendererFrame: stream >> subtime_1 >> subtime_2 >> subtime_3 >> subtime_4; break;
+ // AdaptationLayerFrame: glyphCount, glyphRenderTime, glyphStoreTime
+ case QQmlProfilerClient::SceneGraphAdaptationLayerFrame: stream >> glyphCount >> subtime_2 >> subtime_3; break;
+ // ContextFrame: compiling material time
+ case QQmlProfilerClient::SceneGraphContextFrame: stream >> subtime_1; break;
+ // RenderLoop: syncTime, renderTime, swapTime
+ case QQmlProfilerClient::SceneGraphRenderLoopFrame: stream >> subtime_1 >> subtime_2 >> subtime_3; break;
+ // TexturePrepare: bind, convert, swizzle, upload, mipmap
+ case QQmlProfilerClient::SceneGraphTexturePrepare: stream >> subtime_1 >> subtime_2 >> subtime_3 >> subtime_4 >> subtime_5; break;
+ // TextureDeletion: deletionTime
+ case QQmlProfilerClient::SceneGraphTextureDeletion: stream >> subtime_1; break;
+ // PolishAndSync: polishTime, waitTime, syncTime, animationsTime,
+ case QQmlProfilerClient::SceneGraphPolishAndSync: stream >> subtime_1 >> subtime_2 >> subtime_3 >> subtime_4; break;
+ // WindowsRenderLoop: GL time, make current time, SceneGraph time
+ case QQmlProfilerClient::SceneGraphWindowsRenderShow: stream >> subtime_1 >> subtime_2 >> subtime_3; break;
+ // WindowsAnimations: update time
+ case QQmlProfilerClient::SceneGraphWindowsAnimations: stream >> subtime_1; break;
+ // WindowsRenderWindow: polish time, sync time, render time, swap time
+ case QQmlProfilerClient::SceneGraphWindowsPolishFrame: stream >> subtime_1; break;
+ }
+ break;
+ }
default:
QString failMsg = QString("Unknown message type:") + data.messageType;
QFAIL(qPrintable(failMsg));
@@ -388,6 +434,39 @@ void tst_QQmlProfilerService::pixmapCacheData()
}
+void tst_QQmlProfilerService::scenegraphData()
+{
+ connect(true, "scenegraphTest.qml");
+ QTRY_COMPARE(m_client->state(), QQmlDebugClient::Enabled);
+
+ m_client->setTraceState(true);
+ QVERIFY(QQmlDebugTest::waitForSignal(m_process, SIGNAL(readyReadStandardOutput())));
+ QVERIFY(m_process->output().indexOf(QLatin1String("tick")) != -1);
+ m_client->setTraceState(false);
+
+ QVERIFY2(QQmlDebugTest::waitForSignal(m_client, SIGNAL(complete())), "No trace received in time.");
+ QVERIFY(m_client->traceMessages.count());
+
+ // check that at least one frame was rendered
+ // there should be a SGPolishAndSync + SGRendererFrame + SGRenderLoopFrame sequence
+ // since the rendering happens in a different thread, there could be other unrelated events interleaved
+ int loopcheck = 0;
+ foreach (const QQmlProfilerData &msg, m_client->traceMessages) {
+ if (msg.messageType == QQmlProfilerClient::SceneGraphFrame) {
+ if (loopcheck == 0 && msg.detailType == QQmlProfilerClient::SceneGraphContextFrame)
+ loopcheck = 1;
+ else
+ if (loopcheck == 1 && msg.detailType == QQmlProfilerClient::SceneGraphRendererFrame)
+ loopcheck = 2;
+ else
+ if (loopcheck == 2 && msg.detailType == QQmlProfilerClient::SceneGraphRenderLoopFrame)
+ loopcheck = 3;
+ }
+ }
+
+ QCOMPARE(loopcheck, 3);
+}
+
void tst_QQmlProfilerService::profileOnExit()
{
connect(true, "exit.qml");