Included Basic Profiling Tools

src/coreEngine.cpp

@@ -38,6 +38,9 @@ void CoreEngine::Start()
 	double unprocessedTime = 0;        //Amount of passed time that the engine hasn't accounted for
 	int frames = 0;                    //Number of frames rendered since last
 
+	ProfileTimer sleepTimer;
+	ProfileTimer swapBufferTimer;
+	ProfileTimer windowUpdateTimer;
 	while(m_isRunning)
 	{
 		bool render = false;           //Whether or not the game needs to be rerendered.
@@ -51,11 +54,19 @@ void CoreEngine::Start()
 
 		if(frameCounter >= 1.0)
 		{
-			//The framecounter code here is a temporary, basic profiling tool.
-			//When proper profiling tools are implemented, this should probably be removed.
+			double totalTime = ((1000.0 * frameCounter)/((double)frames));
+			double totalMeasuredTime = 0.0;
 
-			//printf("%i\n",frames);
-			printf("%f ms\n",1000.0/((double)frames));
+			totalMeasuredTime += m_game->DisplayInputTime((double)frames);
+			totalMeasuredTime += m_game->DisplayUpdateTime((double)frames);
+			totalMeasuredTime += m_renderingEngine->DisplayRenderTime((double)frames);
+			totalMeasuredTime += sleepTimer.DisplayAndReset("Sleep Time: ", (double)frames);
+			totalMeasuredTime += windowUpdateTimer.DisplayAndReset("Window Update Time: ", (double)frames);
+			totalMeasuredTime += swapBufferTimer.DisplayAndReset("Buffer Swap Time: ", (double)frames);
+			totalMeasuredTime += m_renderingEngine->DisplayWindowSyncTime((double)frames);
+
+			printf("Other Time:                             %f ms\n", (totalTime - totalMeasuredTime));
+			printf("Total Time:                             %f ms\n\n", totalTime);
 			frames = 0;
 			frameCounter = 0;
 		}
@@ -67,12 +78,14 @@ void CoreEngine::Start()
 		//unaccounted time can then be processed later, since it will remain stored in unprocessedTime.
 		while(unprocessedTime > m_frameTime)
 		{
+			windowUpdateTimer.StartInvocation();
 			m_window->Update();
 
 			if(m_window->IsCloseRequested())
 			{
 				Stop();
 			}
+			windowUpdateTimer.StopInvocation();
 
 			//Input must be processed here because the window may have found new
 			//input events from the OS when it updated. Since inputs can trigger
@@ -94,14 +107,18 @@ void CoreEngine::Start()
 
 			//The newly rendered image will be in the window's backbuffer,
 			//so the buffers must be swapped to display the new image.
+			swapBufferTimer.StartInvocation();
 			m_window->SwapBuffers();
+			swapBufferTimer.StopInvocation();
 			frames++;
 		}
 		else
 		{
 			//If no rendering is needed, sleep for some time so the OS
 			//can use the processor for other tasks.
+			sleepTimer.StartInvocation();
 			Util::Sleep(1);
+			sleepTimer.StopInvocation();
 		}
 	}
 }

src/game.cpp

@@ -4,12 +4,16 @@
 
 void Game::ProcessInput(const Input& input, float delta)
 {
+	m_inputTimer.StartInvocation();
 	m_root.ProcessInputAll(input, delta);
+	m_inputTimer.StopInvocation();
 }
 
 void Game::Update(float delta)
 {
+	m_updateTimer.StartInvocation();
 	m_root.UpdateAll(delta);
+	m_updateTimer.StopInvocation();
 }
 
 void Game::Render(RenderingEngine* renderingEngine)

src/game.h

@@ -3,6 +3,7 @@
 
 #include "gameObject.h"
 #include "coreEngine.h"
+#include "profiling.h"
 
 class Game
 {
@@ -15,14 +16,19 @@ class Game
 	void Update(float delta);
 	void Render(RenderingEngine* renderingEngine);
 
+	inline double DisplayInputTime(double dividend) { return m_inputTimer.DisplayAndReset("Input Time: ", dividend); }
+	inline double DisplayUpdateTime(double dividend) { return m_updateTimer.DisplayAndReset("Update Time: ", dividend); }
+
 	inline void SetEngine(CoreEngine* engine) { m_root.SetEngine(engine); }
 protected:
 	void AddToScene(GameObject* child) { m_root.AddChild(child); }
 private:
 	Game(Game& game) {}
 	void operator=(Game& game) {}
 
-	GameObject m_root;
+	ProfileTimer m_updateTimer;
+	ProfileTimer m_inputTimer;
+	GameObject   m_root;
 };
 
 #endif

src/profiling.cpp

@@ -0,0 +1,45 @@
+#include "profiling.h"
+#include "timing.h"
+#include <cassert>
+#include <iostream>
+
+void ProfileTimer::StartInvocation()
+{
+	m_startTime = Time::GetTime();
+}
+
+void ProfileTimer::StopInvocation()
+{
+	if(m_startTime == 0)
+	{
+		std::cout << "Error: StopInvocation called without matching start invocation" << std::endl;
+		assert(m_startTime != 0);
+	}
+
+	m_numInvocations++;
+	m_totalTime += (Time::GetTime() - m_startTime);
+	m_startTime = 0;
+}
+
+double ProfileTimer::GetTimeAndReset(double dividend)
+{
+	dividend = (dividend == 0) ? m_numInvocations : dividend;
+	double result = (m_totalTime == 0 && dividend == 0.0) ? 0.0 : (1000.0 * m_totalTime)/((double)dividend);
+	m_totalTime = 0.0;
+	m_numInvocations = 0;
+
+	return result;
+}
+
+double ProfileTimer::DisplayAndReset(const std::string& message, double dividend, int displayedMessageLength)
+{
+	std::string whiteSpace = "";
+	for(int i = message.length(); i < displayedMessageLength; i++)
+	{
+		whiteSpace += " ";
+	}
+
+	double time = GetTimeAndReset(dividend);
+	std::cout << message << whiteSpace << time << " ms" << std::endl;
+	return time;
+}

src/profiling.h

@@ -0,0 +1,26 @@
+#ifndef PROFILING_H_INCLUDED
+#define PROFILING_H_INCLUDED
+
+#include <string>
+
+class ProfileTimer
+{
+public:
+	ProfileTimer() :
+		m_numInvocations(0),
+		m_totalTime(0.0),
+		m_startTime(0) {}
+
+	void StartInvocation();
+	void StopInvocation();
+
+	double DisplayAndReset(const std::string& message, double dividend = 0, int displayedMessageLength = 40);
+	double GetTimeAndReset(double dividend = 0);
+protected:
+private:
+	int    m_numInvocations;
+	double m_totalTime;
+	double m_startTime;
+};
+
+#endif // PROFILING_H_INCLUDED

src/renderingEngine.cpp

@@ -45,7 +45,7 @@ RenderingEngine::RenderingEngine(const Window& window) :
 	SetFloat("fxaaReduceMin", 1.0f/128.0f);
 	SetFloat("fxaaReduceMul", 1.0f/8.0f);
 
-	SetTexture("displayTexture", Texture(m_window->GetWidth(), m_window->GetHeight(), 0, GL_TEXTURE_2D, GL_LINEAR, GL_RGBA, GL_RGBA, false, GL_COLOR_ATTACHMENT0));
+	SetTexture("displayTexture", Texture(m_window->GetWidth(), m_window->GetHeight(), 0, GL_TEXTURE_2D, GL_LINEAR, GL_RGBA, GL_RGBA, true, GL_COLOR_ATTACHMENT0));
 
 	glClearColor(0.0f, 0.0f, 0.0f, 0.0f);
 
@@ -117,6 +117,7 @@ void RenderingEngine::ApplyFilter(const Shader& filter, const Texture& source, c
 
 void RenderingEngine::Render(const GameObject& object)
 {
+	m_renderProfileTimer.StartInvocation();
 	GetTexture("displayTexture").BindAsRenderTarget();
 	//m_window->BindAsRenderTarget();
 	//m_tempTarget->BindAsRenderTarget();
@@ -207,5 +208,9 @@ void RenderingEngine::Render(const GameObject& object)
 	}
 
 	SetVector3f("inverseFilterTextureSize", Vector3f(1.0f/GetTexture("displayTexture").GetWidth(), 1.0f/GetTexture("displayTexture").GetHeight(), 0.0f));
+	m_renderProfileTimer.StopInvocation();
+
+	m_windowSyncProfileTimer.StartInvocation();
 	ApplyFilter(m_fxaaFilter, GetTexture("displayTexture"), 0);
+	m_windowSyncProfileTimer.StopInvocation();
 }

src/renderingEngine.h

@@ -7,6 +7,7 @@
 #include "material.h"
 #include "mesh.h"
 #include "window.h"
+#include "profiling.h"
 #include <vector>
 #include <map>
 class GameObject;
@@ -28,6 +29,9 @@ class RenderingEngine : public MappedValues
 		throw uniformType + " is not supported by the rendering engine";
 	}
 
+	inline double DisplayRenderTime(double dividend) { return m_renderProfileTimer.DisplayAndReset("Render Time: ", dividend); }
+	inline double DisplayWindowSyncTime(double dividend) { return m_windowSyncProfileTimer.DisplayAndReset("Window Sync Time: ", dividend); }
+
 	inline const BaseLight& GetActiveLight()                           const { return *m_activeLight; }
 	inline unsigned int GetSamplerSlot(const std::string& samplerName) const { return m_samplerMap.find(samplerName)->second; }
 	inline const Matrix4f& GetLightMatrix()                            const { return m_lightMatrix; }
@@ -37,6 +41,8 @@ class RenderingEngine : public MappedValues
 	static const int NUM_SHADOW_MAPS = 10;
 	static const Matrix4f BIAS_MATRIX;
 
+	ProfileTimer                        m_renderProfileTimer;
+	ProfileTimer                        m_windowSyncProfileTimer;
 	Transform                           m_planeTransform;
 	Mesh                                m_plane;