Use categorized logging for all things scenegraph.

Change-Id: I865ee838b0fd6c257b7189f24130012b98206fd1
Reviewed-by: Shawn Rutledge <shawn.rutledge@digia.com>

2 files changed, 13 insertions, 44 deletions

diff --git a/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp b/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp
index b3342be5ce..c064023010 100644
--- a/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp
+++ b/src/quick/scenegraph/coreapi/qsgbatchrenderer.cpp
@@ -80,10 +80,7 @@ const bool debug_noalpha    = qgetenv("QSG_RENDERER_DEBUG").contains("noalpha");
 const bool debug_noopaque   = qgetenv("QSG_RENDERER_DEBUG").contains("noopaque");
 const bool debug_noclip     = qgetenv("QSG_RENDERER_DEBUG").contains("noclip");
 
-#ifndef QSG_NO_RENDER_TIMING
-static bool qsg_render_timing = !qgetenv("QSG_RENDER_TIMING").isEmpty();
 static QElapsedTimer qsg_renderer_timer;
-#endif
 
 #define QSGNODE_TRAVERSE(NODE) for (QSGNode *child = NODE->firstChild(); child; child = child->nextSibling())
 #define SHADOWNODE_TRAVERSE(NODE) for (QList<Node *>::const_iterator child = NODE->children.constBegin(); child != NODE->children.constEnd(); ++child)
@@ -134,10 +131,8 @@ ShaderManager::Shader *ShaderManager::prepareMaterial(QSGMaterial *material)
     if (shader)
         return shader;
 
-#ifndef QSG_NO_RENDER_TIMING
-    if (qsg_render_timing  || QQuickProfiler::enabled)
+    if (QSG_LOG_TIME_COMPILATION().isDebugEnabled() || QQuickProfiler::enabled)
         qsg_renderer_timer.start();
-#endif
 
     QSGMaterialShader *s = material->createShader();
     QOpenGLContext *ctx = QOpenGLContext::currentContext();
@@ -165,13 +160,10 @@ ShaderManager::Shader *ShaderManager::prepareMaterial(QSGMaterial *material)
     Q_ASSERT(shader->pos_order >= 0);
     Q_ASSERT(shader->id_zRange >= 0);
 
-#ifndef QSG_NO_RENDER_TIMING
-    if (qsg_render_timing)
-        qDebug("   - compiling material: %dms", (int) qsg_renderer_timer.elapsed());
+    qCDebug(QSG_LOG_TIME_COMPILATION, "shader compiled in %dms", (int) qsg_renderer_timer.elapsed());
 
     Q_QUICK_SG_PROFILE1(QQuickProfiler::SceneGraphContextFrame, (
             qsg_renderer_timer.nsecsElapsed()));
-#endif
 
     rewrittenShaders[type] = shader;
     return shader;
@@ -184,10 +176,8 @@ ShaderManager::Shader *ShaderManager::prepareMaterialNoRewrite(QSGMaterial *mate
     if (shader)
         return shader;
 
-#ifndef QSG_NO_RENDER_TIMING
-    if (qsg_render_timing  || QQuickProfiler::enabled)
+    if (QSG_LOG_TIME_COMPILATION().isDebugEnabled() || QQuickProfiler::enabled)
         qsg_renderer_timer.start();
-#endif
 
     QSGMaterialShader *s = static_cast<QSGMaterialShader *>(material->createShader());
     context->compile(s, material);
@@ -201,14 +191,10 @@ ShaderManager::Shader *ShaderManager::prepareMaterialNoRewrite(QSGMaterial *mate
 
     stockShaders[type] = shader;
 
-#ifndef QSG_NO_RENDER_TIMING
-    if (qsg_render_timing)
-        qDebug("   - compiling material: %dms", (int) qsg_renderer_timer.elapsed());
+    qCDebug(QSG_LOG_TIME_COMPILATION, "shader compiled in %dms (no rewrite)", (int) qsg_renderer_timer.elapsed());
 
     Q_QUICK_SG_PROFILE1(QQuickProfiler::SceneGraphContextFrame, (
             qsg_renderer_timer.nsecsElapsed()));
-#endif
-
     return shader;
 }
 
diff --git a/src/quick/scenegraph/coreapi/qsgrenderer.cpp b/src/quick/scenegraph/coreapi/qsgrenderer.cpp
index 4a26eae6cd..d64bd4e14a 100644
--- a/src/quick/scenegraph/coreapi/qsgrenderer.cpp
+++ b/src/quick/scenegraph/coreapi/qsgrenderer.cpp
@@ -63,12 +63,9 @@ QT_BEGIN_NAMESPACE
 
 static bool qsg_sanity_check = qgetenv("QSG_SANITY_CHECK").toInt();
 
-#ifndef QSG_NO_RENDER_TIMING
-static bool qsg_render_timing = !qgetenv("QSG_RENDER_TIMING").isEmpty();
 static QElapsedTimer frameTimer;
 static qint64 preprocessTime;
 static qint64 updatePassTime;
-#endif
 
 void QSGBindable::clear(QSGRenderer::ClearMode mode) const
 {
@@ -226,22 +223,18 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
     m_is_rendering = true;
 
 
-#ifndef QSG_NO_RENDER_TIMING
-    bool profileFrames = qsg_render_timing || QQuickProfiler::enabled;
+    bool profileFrames = QSG_LOG_TIME_RENDERER().isDebugEnabled() || QQuickProfiler::enabled;
     if (profileFrames)
         frameTimer.start();
     qint64 bindTime = 0;
     qint64 renderTime = 0;
-#endif
 
     m_bindable = &bindable;
     preprocess();
 
     bindable.bind();
-#ifndef QSG_NO_RENDER_TIMING
     if (profileFrames)
         bindTime = frameTimer.nsecsElapsed();
-#endif
 
     // Sanity check that attribute registers are disabled
     if (qsg_sanity_check) {
@@ -257,10 +250,8 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
     }
 
     render();
-#ifndef QSG_NO_RENDER_TIMING
     if (profileFrames)
         renderTime = frameTimer.nsecsElapsed();
-#endif
 
     glDisable(GL_SCISSOR_TEST);
     m_is_rendering = false;
@@ -277,15 +268,13 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
         m_index_buffer_bound = false;
     }
 
-#ifndef QSG_NO_RENDER_TIMING
-    if (qsg_render_timing) {
-        qDebug(" - Breakdown of render time: preprocess=%d, updates=%d, binding=%d, render=%d, total=%d",
-               int(preprocessTime / 1000000),
-               int((updatePassTime - preprocessTime) / 1000000),
-               int((bindTime - updatePassTime) / 1000000),
-               int((renderTime - bindTime) / 1000000),
-               int(renderTime / 1000000));
-    }
+    qCDebug(QSG_LOG_TIME_RENDERER,
+            "time in renderer: total=%dms, preprocess=%d, updates=%d, binding=%d, rendering=%d",
+            int(renderTime / 1000000),
+            int(preprocessTime / 1000000),
+            int((updatePassTime - preprocessTime) / 1000000),
+            int((bindTime - updatePassTime) / 1000000),
+            int((renderTime - bindTime) / 1000000));
 
     Q_QUICK_SG_PROFILE1(QQuickProfiler::SceneGraphRendererFrame, (
             preprocessTime,
@@ -293,7 +282,6 @@ void QSGRenderer::renderScene(const QSGBindable &bindable)
             bindTime - updatePassTime,
             renderTime - bindTime));
 
-#endif
 }
 
 void QSGRenderer::setProjectionMatrixToDeviceRect()
@@ -374,19 +362,14 @@ void QSGRenderer::preprocess()
         }
     }
 
-#ifndef QSG_NO_RENDER_TIMING
-    bool profileFrames = qsg_render_timing || QQuickProfiler::enabled;
+    bool profileFrames = QSG_LOG_TIME_RENDERER().isDebugEnabled()|| QQuickProfiler::enabled;
     if (profileFrames)
         preprocessTime = frameTimer.nsecsElapsed();
-#endif
 
     nodeUpdater()->updateStates(m_root_node);
 
-#ifndef QSG_NO_RENDER_TIMING
     if (profileFrames)
         updatePassTime = frameTimer.nsecsElapsed();
-#endif
-
 }
 
 void QSGRenderer::addNodesToPreprocess(QSGNode *node)