Add Improved Profiling statistics

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()

rwengine/include/engine/RWTypes.hpp

@@ -8,6 +8,8 @@
 #include <glm/glm.hpp>
 #include <memory>
 
+#define RW_USING(feature) 1 == feature
+
 #define NO_WATER_INDEX 48
 #define WATER_LQ_DATA_SIZE 64
 #define WATER_HQ_DATA_SIZE 128

rwengine/include/render/GameRenderer.hpp

@@ -194,10 +194,11 @@ public:
 	WaterRenderer water;
 	TextRenderer text;
 
-	// Rendering timers
+	// Profiling data
-	GLuint timeObj;
+	Renderer::ProfileInfo profObjects;
-	GLuint timeSky;
+	Renderer::ProfileInfo profSky;
-	GLuint timeWater;
+	Renderer::ProfileInfo profWater;
+	Renderer::ProfileInfo profEffects;
 };
 
 #endif

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;
 };

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);
 

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, &current_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];
 }

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<std::string, Renderer::ProfileInfo*> 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 << " World time: " << (worldRenderTime.duration/1000000) << "ms\n";
-	ss << "  Objects: " << (renderer->timeObj/1000000) << "ms\n";
+	for(auto& perf : profGroups)
-	ss << "  Water: " << (renderer->timeWater/1000000) << "ms\n";
+	{
-	ss << "  Sky: " << (renderer->timeSky/1000000) << "ms\n";
+		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;

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);
 };