From: Gunnar Sletta Date: Wed, 30 Jan 2013 10:13:09 +0000 (+0100) Subject: Added to QML_RENDERER_TIMING logic to capture most render bottlenecks. X-Git-Tag: upstream/5.2.1~932 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=3e3c59b2c05463eea9a9ad99125aac909e70a996;p=platform%2Fupstream%2Fqtdeclarative.git Added to QML_RENDERER_TIMING logic to capture most render bottlenecks. The typical bottlenecks during rendering are usually compiling shader programs, uploading textures and preparing glyphs, so add profiling data around them. Change-Id: I9c330a0f6b769836d303a035b2c0dce832842aec Reviewed-by: Samuel Rødal --- diff --git a/src/quick/scenegraph/coreapi/qsgrenderer.cpp b/src/quick/scenegraph/coreapi/qsgrenderer.cpp index 6f9d380..02eec70 100644 --- a/src/quick/scenegraph/coreapi/qsgrenderer.cpp +++ b/src/quick/scenegraph/coreapi/qsgrenderer.cpp @@ -60,8 +60,7 @@ QT_BEGIN_NAMESPACE -#define QSG_RENDERER_TIMING -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING static bool qsg_render_timing = !qgetenv("QML_RENDERER_TIMING").isEmpty(); static QTime frameTimer; static int preprocessTime; @@ -237,7 +236,7 @@ void QSGRenderer::renderScene(const QSGBindable &bindable) m_is_rendering = true; -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING if (qsg_render_timing) frameTimer.start(); int bindTime = 0; @@ -248,7 +247,7 @@ void QSGRenderer::renderScene(const QSGBindable &bindable) preprocess(); bindable.bind(); -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING if (qsg_render_timing) bindTime = frameTimer.elapsed(); #endif @@ -269,7 +268,7 @@ void QSGRenderer::renderScene(const QSGBindable &bindable) #endif render(); -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING if (qsg_render_timing) renderTime = frameTimer.elapsed(); #endif @@ -289,9 +288,9 @@ void QSGRenderer::renderScene(const QSGBindable &bindable) m_index_buffer_bound = false; } -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING if (qsg_render_timing) { - printf(" - Breakdown of frametime: preprocess=%d, updates=%d, binding=%d, render=%d, total=%d\n", + printf(" - Breakdown of render time: preprocess=%d, updates=%d, binding=%d, render=%d, total=%d\n", preprocessTime, updatePassTime - preprocessTime, bindTime - updatePassTime, @@ -379,7 +378,7 @@ void QSGRenderer::preprocess() } } -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING if (qsg_render_timing) preprocessTime = frameTimer.elapsed(); #endif @@ -387,7 +386,7 @@ void QSGRenderer::preprocess() nodeUpdater()->setToplevelOpacity(context()->renderAlpha()); nodeUpdater()->updateStates(m_root_node); -#ifdef QSG_RENDERER_TIMING +#ifndef QSG_NO_RENDERER_TIMING if (qsg_render_timing) updatePassTime = frameTimer.elapsed(); #endif diff --git a/src/quick/scenegraph/qsgadaptationlayer.cpp b/src/quick/scenegraph/qsgadaptationlayer.cpp index 87b13d8..4e8bafb 100644 --- a/src/quick/scenegraph/qsgadaptationlayer.cpp +++ b/src/quick/scenegraph/qsgadaptationlayer.cpp @@ -48,8 +48,14 @@ #include #include +#include + QT_BEGIN_NAMESPACE +#ifndef QSG_NO_RENDERER_TIMING +static bool qsg_render_timing = !qgetenv("QML_RENDERER_TIMING").isEmpty(); +static QElapsedTimer qsg_render_timer; +#endif QSGDistanceFieldGlyphCache::Texture QSGDistanceFieldGlyphCache::s_emptyTexture; @@ -155,6 +161,11 @@ void QSGDistanceFieldGlyphCache::update() if (m_pendingGlyphs.isEmpty()) return; +#ifndef QSG_NO_RENDERER_TIMING + if (qsg_render_timing) + qsg_render_timer.start(); +#endif + QHash distanceFields; for (int i = 0; i < m_pendingGlyphs.size(); ++i) { @@ -164,9 +175,27 @@ void QSGDistanceFieldGlyphCache::update() distanceFields.insert(glyphIndex, distanceField); } +#ifndef QSG_NO_RENDERER_TIMING + int renderTime = 0; + int count = m_pendingGlyphs.size(); + if (qsg_render_timing) + renderTime = qsg_render_timer.elapsed(); +#endif + m_pendingGlyphs.reset(); storeGlyphs(distanceFields); + +#ifndef QSG_NO_RENDERER_TIMING + if (qsg_render_timing) { + printf(" - glyphs: count=%d, render=%d, store=%d, total=%d\n", + count, + renderTime, + (int) qsg_render_timer.elapsed() - renderTime, + (int) qsg_render_timer.elapsed()); + + } +#endif } void QSGDistanceFieldGlyphCache::setGlyphsPosition(const QList &glyphs) diff --git a/src/quick/scenegraph/qsgcontext.cpp b/src/quick/scenegraph/qsgcontext.cpp index c9ac190..e7e10ec 100644 --- a/src/quick/scenegraph/qsgcontext.cpp +++ b/src/quick/scenegraph/qsgcontext.cpp @@ -71,6 +71,12 @@ DEFINE_BOOL_CONFIG_OPTION(qmlFlashMode, QML_FLASH_MODE) DEFINE_BOOL_CONFIG_OPTION(qmlTranslucentMode, QML_TRANSLUCENT_MODE) DEFINE_BOOL_CONFIG_OPTION(qmlDisableDistanceField, QML_DISABLE_DISTANCEFIELD) + +#ifndef QSG_NO_RENDERER_TIMING +static bool qsg_render_timing = !qgetenv("QML_RENDERER_TIMING").isEmpty(); +static QElapsedTimer qsg_renderer_timer; +#endif + /* Comments about this class from Gunnar: @@ -463,11 +469,21 @@ QSGMaterialShader *QSGContext::prepareMaterial(QSGMaterial *material) if (shader) return shader; +#ifndef QSG_NO_RENDERER_TIMING + if (qsg_render_timing) + qsg_renderer_timer.start(); +#endif + shader = material->createShader(); shader->compile(); shader->initialize(); d->materials[type] = shader; +#ifndef QSG_NO_RENDERER_TIMING + if (qsg_render_timing) + printf(" - compiling material: %dms\n", (int) qsg_renderer_timer.elapsed()); +#endif + return shader; } diff --git a/src/quick/scenegraph/qsgthreadedrenderloop.cpp b/src/quick/scenegraph/qsgthreadedrenderloop.cpp index 5ec6de2..4e8050d 100644 --- a/src/quick/scenegraph/qsgthreadedrenderloop.cpp +++ b/src/quick/scenegraph/qsgthreadedrenderloop.cpp @@ -133,8 +133,7 @@ static inline int qsgrl_animation_interval() { } -#define QQUICK_WINDOW_TIMING -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING static bool qquick_window_timing = !qgetenv("QML_WINDOW_TIMING").isEmpty(); static QTime threadTimer; static int syncTime; @@ -537,7 +536,7 @@ void QSGRenderThread::sync() void QSGRenderThread::syncAndRender() { -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing) sinceLastTime = threadTimer.restart(); #endif @@ -556,7 +555,7 @@ void QSGRenderThread::syncAndRender() sync(); } -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing) syncTime = threadTimer.elapsed(); #endif @@ -570,7 +569,7 @@ void QSGRenderThread::syncAndRender() } gl->makeCurrent(w.window); d->renderSceneGraph(w.size); -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing && i == 0) renderTime = threadTimer.elapsed(); #endif @@ -579,7 +578,7 @@ void QSGRenderThread::syncAndRender() } RLDEBUG(" Render: - rendering done"); -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing) qDebug("window Time: sinceLast=%d, sync=%d, first render=%d, after final swap=%d", sinceLastTime, @@ -885,10 +884,10 @@ void QSGThreadedRenderLoop::polishAndSync() if (!anyoneShowing()) return; -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING QElapsedTimer timer; - int polishTime; - int waitTime; + int polishTime = 0; + int waitTime = 0; if (qquick_window_timing) timer.start(); #endif @@ -899,7 +898,7 @@ void QSGThreadedRenderLoop::polishAndSync() QQuickWindowPrivate *d = QQuickWindowPrivate::get(w.window); d->polishItems(); } -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing) polishTime = timer.elapsed(); #endif @@ -916,7 +915,7 @@ void QSGThreadedRenderLoop::polishAndSync() QCoreApplication::postEvent(m_thread, event); RLDEBUG("GUI: - wait for sync..."); -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing) waitTime = timer.elapsed(); #endif @@ -925,7 +924,7 @@ void QSGThreadedRenderLoop::polishAndSync() m_thread->mutex.unlock(); RLDEBUG("GUI: - unlocked after sync..."); -#ifdef QQUICK_WINDOW_TIMING +#ifndef QSG_NO_WINDOW_TIMING if (qquick_window_timing) qDebug(" - polish=%d, wait=%d, sync=%d", polishTime, waitTime - polishTime, int(timer.elapsed() - waitTime)); #endif diff --git a/src/quick/scenegraph/util/qsgtexture.cpp b/src/quick/scenegraph/util/qsgtexture.cpp index 16cc461..c6a5672 100644 --- a/src/quick/scenegraph/util/qsgtexture.cpp +++ b/src/quick/scenegraph/util/qsgtexture.cpp @@ -65,6 +65,12 @@ #include #endif +#ifndef QSG_NO_RENDERER_TIMING +static bool qsg_render_timing = !qgetenv("QML_RENDERER_TIMING").isEmpty(); +static QElapsedTimer qsg_renderer_timer; +#endif + + QT_BEGIN_NAMESPACE inline static bool isPowerOfTwo(int x) @@ -596,14 +602,30 @@ void QSGPlainTexture::bind() m_dirty_texture = false; +#ifndef QSG_NO_RENDERER_TIMING + if (qsg_render_timing) + qsg_renderer_timer.start(); +#endif if (m_image.isNull()) { - if (m_texture_id && m_owns_texture) + if (m_texture_id && m_owns_texture) { glDeleteTextures(1, &m_texture_id); +#ifndef QSG_NO_RENDERER_TIMING + if (qsg_render_timing) { + printf(" - texture deleted in %dms (size: %dx%d)\n", + (int) qsg_renderer_timer.elapsed(), + m_texture_size.width(), + m_texture_size.height()); + } +#endif + } m_texture_id = 0; m_texture_size = QSize(); m_has_mipmaps = false; m_has_alpha = false; + + + return; } @@ -611,6 +633,12 @@ void QSGPlainTexture::bind() glGenTextures(1, &m_texture_id); glBindTexture(GL_TEXTURE_2D, m_texture_id); +#ifndef QSG_NO_RENDERER_TIMING + int bindTime = 0; + if (qsg_render_timing) + bindTime = qsg_renderer_timer.elapsed(); +#endif + // ### TODO: check for out-of-memory situations... int w = m_image.width(); int h = m_image.height(); @@ -619,21 +647,68 @@ void QSGPlainTexture::bind() ? m_image : m_image.convertToFormat(QImage::Format_ARGB32_Premultiplied); +#ifndef QSG_NO_RENDERER_TIMING + int convertTime = 0; + if (qsg_render_timing) + convertTime = qsg_renderer_timer.elapsed(); +#endif + updateBindOptions(m_dirty_bind_options); #ifdef QT_OPENGL_ES qsg_swizzleBGRAToRGBA(&tmp); +#ifndef QSG_NO_RENDERER_TIMING + int swizzleTime = 0; + if (qsg_render_timing) + swizzleTime = qsg_renderer_timer.elapsed(); +#endif glTexImage2D(GL_TEXTURE_2D, 0, GL_RGBA, w, h, 0, GL_RGBA, GL_UNSIGNED_BYTE, tmp.constBits()); #else glTexImage2D(GL_TEXTURE_2D, 0, GL_RGBA, w, h, 0, GL_BGRA, GL_UNSIGNED_BYTE, tmp.constBits()); #endif +#ifndef QSG_NO_RENDERER_TIMING + int uploadTime = 0; + if (qsg_render_timing) + uploadTime = qsg_renderer_timer.elapsed(); +#endif + + if (m_has_mipmaps) { QOpenGLContext *ctx = QOpenGLContext::currentContext(); ctx->functions()->glGenerateMipmap(GL_TEXTURE_2D); m_mipmaps_generated = true; } +#ifndef QSG_NO_RENDERER_TIMING + int mipmapTime = 0; + if (qsg_render_timing) { + mipmapTime = qsg_renderer_timer.elapsed(); + +#ifdef QT_OPENGL_ES + printf(" - plaintexture(%dx%d) bind=%d, convert=%d, swizzle=%d, upload=%d, mipmap=%d, total=%d\n", + m_texture_size.width(), m_texture_size.height(), + bindTime, + convertTime - bindTime, + swizzleTime - convertTime, + uploadTime - swizzleTime, + mipmapTime - uploadTime, + (int) qsg_renderer_timer.elapsed()); +#else + printf(" - plaintexture(%dx%d): bind=%d, convert=%d, upload=%d, mipmap=%d, total=%d\n", + m_texture_size.width(), m_texture_size.height(), + bindTime, + convertTime - bindTime, + uploadTime - convertTime, + mipmapTime - uploadTime, + (int) qsg_renderer_timer.elapsed()); +#endif + + } + +#endif + + m_texture_size = QSize(w, h); m_texture_rect = QRectF(0, 0, 1, 1);