From 97afc19cfb019d606057a05c73f549c0e6673676 Mon Sep 17 00:00:00 2001 From: Daniel Evans Date: Sun, 12 Apr 2015 19:47:47 +0100 Subject: [PATCH] Add Improved Profiling statistics --- CMakeLists.txt | 9 ++++ rwengine/include/engine/RWTypes.hpp | 2 + rwengine/include/render/GameRenderer.hpp | 9 ++-- rwengine/include/render/OpenGLRenderer.hpp | 33 ++++++++++-- rwengine/src/render/GameRenderer.cpp | 10 ++-- rwengine/src/render/OpenGLRenderer.cpp | 63 +++++++++++++++++++--- rwgame/RWGame.cpp | 20 +++++-- rwgame/RWGame.hpp | 2 +- 8 files changed, 123 insertions(+), 25 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index f5790c75..edc3ec65 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -8,6 +8,9 @@ SET(BUILD_TESTS TRUE CACHE BOOL "Build test suite") SET(BUILD_OLD_TOOLS FALSE CACHE BOOL "Build old datadump and analyzer tools") SET(BUILD_TOOLS FALSE CACHE BOOL "Build editor application") +# Features +SET(ENABLE_PROFILE_RENDERER TRUE CACHE BOOL "Enable higher precision rendering profiler") + # Options SET(ENABLE_SCRIPT_DEBUG FALSE CACHE BOOL "Enable verbose script execution") @@ -26,6 +29,12 @@ ENDIF() # Make GLM use radians add_definitions(-DGLM_FORCE_RADIANS) +IF(${ENABLE_PROFILE_RENDERER}) + add_definitions(-DRENDER_PROFILER=1) +else() + add_definitions(-DRENDER_PROFILER=0) +ENDIF() + IF(${ENABLE_SCRIPT_DEBUG}) add_definitions(-DSCM_DEBUG_INSTRUCTIONS) ENDIF() diff --git a/rwengine/include/engine/RWTypes.hpp b/rwengine/include/engine/RWTypes.hpp index 876859ef..f3a47e42 100644 --- a/rwengine/include/engine/RWTypes.hpp +++ b/rwengine/include/engine/RWTypes.hpp @@ -8,6 +8,8 @@ #include #include +#define RW_USING(feature) 1 == feature + #define NO_WATER_INDEX 48 #define WATER_LQ_DATA_SIZE 64 #define WATER_HQ_DATA_SIZE 128 diff --git a/rwengine/include/render/GameRenderer.hpp b/rwengine/include/render/GameRenderer.hpp index 5a30a7ef..64c21422 100644 --- a/rwengine/include/render/GameRenderer.hpp +++ b/rwengine/include/render/GameRenderer.hpp @@ -194,10 +194,11 @@ public: WaterRenderer water; TextRenderer text; - // Rendering timers - GLuint timeObj; - GLuint timeSky; - GLuint timeWater; + // Profiling data + Renderer::ProfileInfo profObjects; + Renderer::ProfileInfo profSky; + Renderer::ProfileInfo profWater; + Renderer::ProfileInfo profEffects; }; #endif diff --git a/rwengine/include/render/OpenGLRenderer.hpp b/rwengine/include/render/OpenGLRenderer.hpp index 94e5ff2e..ed48010c 100644 --- a/rwengine/include/render/OpenGLRenderer.hpp +++ b/rwengine/include/render/OpenGLRenderer.hpp @@ -117,11 +117,32 @@ public: const SceneUniformData& getSceneData() const; + /** + * Profiling data returned by popDebugGroup. + * Not all fields will be populated, depending on + * USING(RENDER_PROFILER) + */ + struct ProfileInfo + { + GLuint64 timerStart; + GLuint64 duration; + unsigned int primitives; + unsigned int draws; + unsigned int textures; + unsigned int buffers; + unsigned int uploads; + }; + /** * Signals the start of a debug group */ virtual void pushDebugGroup(const std::string& title) = 0; - virtual GLuint popDebugGroup() = 0; + /** + * Ends the current debug group and returns the profiling information + * for that group. The returned value is valid until the next call to + * pushDebugGroup + */ + virtual const ProfileInfo& popDebugGroup() = 0; private: glm::ivec2 viewport; @@ -185,7 +206,7 @@ public: void invalidate(); virtual void pushDebugGroup(const std::string& title); - virtual GLuint popDebugGroup(); + virtual const ProfileInfo& popDebugGroup(); private: DrawBuffer* currentDbuff; @@ -205,13 +226,19 @@ private: currentUBO = buffer; } glBufferData(GL_UNIFORM_BUFFER, sizeof(T), &data, GL_DYNAMIC_DRAW); +#if RW_USING(RENDER_PROFILER) + if( currentDebugDepth > 0 ) + { + profileInfo[currentDebugDepth-1].uploads++; + } +#endif } GLuint UBOObject; GLuint UBOScene; // Debug group profiling timers - GLuint64 debugTimes[MAX_DEBUG_DEPTH]; + ProfileInfo profileInfo[MAX_DEBUG_DEPTH]; GLuint debugQuery; int currentDebugDepth; }; diff --git a/rwengine/src/render/GameRenderer.cpp b/rwengine/src/render/GameRenderer.cpp index 238ad760..0cff80f9 100644 --- a/rwengine/src/render/GameRenderer.cpp +++ b/rwengine/src/render/GameRenderer.cpp @@ -233,8 +233,6 @@ void GameRenderer::renderWorld(const ViewCamera &camera, float alpha) // Store the input camera, _camera = camera; - timeObj = timeSky = timeWater = 0; - // Set the viewport const glm::ivec2& vp = getRenderer()->getViewport(); glViewport(0, 0, vp.x, vp.y); @@ -368,7 +366,7 @@ void GameRenderer::renderWorld(const ViewCamera &camera, float alpha) transparentDrawQueue.clear(); renderer->popDebugGroup(); - timeObj = renderer->popDebugGroup(); + profObjects = renderer->popDebugGroup(); // Render arrows above anything that isn't radar only (or hidden) ModelRef& arrowModel = engine->gameData.models["arrow"]; @@ -426,7 +424,7 @@ void GameRenderer::renderWorld(const ViewCamera &camera, float alpha) water.render(this, engine); - timeWater = renderer->popDebugGroup(); + profWater = renderer->popDebugGroup(); renderer->pushDebugGroup("Sky"); @@ -442,11 +440,11 @@ void GameRenderer::renderWorld(const ViewCamera &camera, float alpha) renderer->draw(glm::mat4(), &skyDbuff, dp); - timeSky = renderer->popDebugGroup(); + profSky = renderer->popDebugGroup(); renderer->pushDebugGroup("Effects"); renderEffects(); - renderer->popDebugGroup(); + profEffects = renderer->popDebugGroup(); glDisable(GL_DEPTH_TEST); diff --git a/rwengine/src/render/OpenGLRenderer.cpp b/rwengine/src/render/OpenGLRenderer.cpp index dc3c507d..bfa94435 100644 --- a/rwengine/src/render/OpenGLRenderer.cpp +++ b/rwengine/src/render/OpenGLRenderer.cpp @@ -121,6 +121,12 @@ void OpenGLRenderer::useDrawBuffer(DrawBuffer* dbuff) glBindVertexArray(dbuff->getVAOName()); currentDbuff = dbuff; bufferCounter++; +#if RW_USING(RENDER_PROFILER) + if( currentDebugDepth > 0 ) + { + profileInfo[currentDebugDepth-1].buffers++; + } +#endif } } @@ -132,6 +138,13 @@ void OpenGLRenderer::useTexture(GLuint unit, GLuint tex) glBindTexture(GL_TEXTURE_2D, tex); currentTextures[unit] = tex; textureCounter++; +#if RW_USING(RENDER_PROFILER) + if( currentDebugDepth > 0 ) + { + profileInfo[currentDebugDepth-1].textures++; + } +#endif + } } @@ -261,6 +274,14 @@ void OpenGLRenderer::draw(const glm::mat4& model, DrawBuffer* draw, const Render uploadUBO(UBOObject, oudata); drawCounter++; +#if RW_USING(RENDER_PROFILER) + if( currentDebugDepth > 0 ) + { + profileInfo[currentDebugDepth-1].draws++; + profileInfo[currentDebugDepth-1].primitives += p.count; + } +#endif + glDrawElements(draw->getFaceType(), p.count, GL_UNSIGNED_INT, (void*) (sizeof(RenderIndex) * p.start)); } @@ -284,6 +305,14 @@ void OpenGLRenderer::drawArrays(const glm::mat4& model, DrawBuffer* draw, const uploadUBO(UBOObject, oudata); drawCounter++; +#if RW_USING(RENDER_PROFILER) + if( currentDebugDepth > 0 ) + { + profileInfo[currentDebugDepth-1].draws++; + profileInfo[currentDebugDepth-1].primitives += p.count; + } +#endif + glDrawArrays(draw->getFaceType(), p.start, p.count); } @@ -297,30 +326,52 @@ void OpenGLRenderer::invalidate() void OpenGLRenderer::pushDebugGroup(const std::string& title) { +#if RW_USING(RENDER_PROFILER) if( GLEW_KHR_debug ) { glPushDebugGroup(GL_DEBUG_SOURCE_APPLICATION, 0, -1, title.c_str()); + ProfileInfo& prof = profileInfo[currentDebugDepth]; + prof.buffers = prof.draws = prof.textures = prof.uploads = prof.primitives = 0; glQueryCounter(debugQuery, GL_TIMESTAMP); - glGetQueryObjectui64v(debugQuery, GL_QUERY_RESULT, &debugTimes[currentDebugDepth]); + glGetQueryObjectui64v(debugQuery, GL_QUERY_RESULT, &prof.timerStart); + currentDebugDepth++; assert( currentDebugDepth < MAX_DEBUG_DEPTH ); } +#endif } -GLuint OpenGLRenderer::popDebugGroup() +const Renderer::ProfileInfo& OpenGLRenderer::popDebugGroup() { +#if RW_USING(RENDER_PROFILER) if( GLEW_KHR_debug ) { glPopDebugGroup(); currentDebugDepth--; assert( currentDebugDepth >= 0 ); - + + ProfileInfo& prof = profileInfo[currentDebugDepth]; + glQueryCounter(debugQuery, GL_TIMESTAMP); GLuint64 current_time; glGetQueryObjectui64v(debugQuery, GL_QUERY_RESULT, ¤t_time); - - return current_time - debugTimes[currentDebugDepth]; + + prof.duration = current_time - prof.timerStart; + + // Add counters to the parent group + if( currentDebugDepth > 0 ) + { + ProfileInfo& p = profileInfo[currentDebugDepth-1]; + p.draws += prof.draws; + p.buffers += prof.buffers; + p.primitives += prof.primitives; + p.textures += prof.textures; + p.uploads += prof.uploads; + } + + return prof; } - return 0; +#endif + return profileInfo[0]; } diff --git a/rwgame/RWGame.cpp b/rwgame/RWGame.cpp index a45a9ff1..c8fa7cd6 100644 --- a/rwgame/RWGame.cpp +++ b/rwgame/RWGame.cpp @@ -448,7 +448,7 @@ void RWGame::render(float alpha, float time) drawOnScreenText(engine, renderer); } -void RWGame::renderDebugStats(float time, GLuint worldRenderTime) +void RWGame::renderDebugStats(float time, Renderer::ProfileInfo& worldRenderTime) { // Turn time into milliseconds float time_ms = time * 1000.f; @@ -466,16 +466,26 @@ void RWGame::renderDebugStats(float time, GLuint worldRenderTime) time_average /= average_every_frame; } + std::map profGroups { + {"Objects", &renderer->profObjects}, + {"Effects", &renderer->profEffects}, + {"Sky", &renderer->profSky}, + {"Water", &renderer->profWater}, + }; + std::stringstream ss; ss << "Frametime: " << time_ms << " (FPS " << (1.f/time) << ")\n"; ss << "Average (per " << average_every_frame << " frames); Frametime: " << time_average << " (FPS " << (1000.f/time_average) << ")\n"; ss << "Draws: " << lastDraws << " (" << renderer->culled << " Culls)\n"; ss << " Texture binds: " << renderer->getRenderer()->getTextureCount() << "\n"; ss << " Buffer binds: " << renderer->getRenderer()->getBufferCount() << "\n"; - ss << " World time: " << (worldRenderTime/1000000) << "ms\n"; - ss << " Objects: " << (renderer->timeObj/1000000) << "ms\n"; - ss << " Water: " << (renderer->timeWater/1000000) << "ms\n"; - ss << " Sky: " << (renderer->timeSky/1000000) << "ms\n"; + ss << " World time: " << (worldRenderTime.duration/1000000) << "ms\n"; + for(auto& perf : profGroups) + { + ss << " " << perf.first << ": " + << perf.second->draws << " draws " << perf.second->primitives << " prims " + << (perf.second->duration/1000000) << "ms\n"; + } // Count the number of interesting objects. int peds = 0, cars = 0; diff --git a/rwgame/RWGame.hpp b/rwgame/RWGame.hpp index 8970fd90..458da14f 100644 --- a/rwgame/RWGame.hpp +++ b/rwgame/RWGame.hpp @@ -88,7 +88,7 @@ private: void tick(float dt); void render(float alpha, float dt); - void renderDebugStats(float time, GLuint worldRenderTime); + void renderDebugStats(float time, Renderer::ProfileInfo& worldRenderTime); void globalKeyEvent(const sf::Event& event); };