Tank War

Project Description:

This was a project that helped me understand 3D rendering concepts, Shadow Mapping, Performance Profiler, Threaded Logger, Transform Hierarchies, etc. The list of the features I worked on for this project is under the summary section.

Development Specification:

Engine: Personal Engine (C++)
Development Time: 2 Months
Rendering API: OpenGL 4.2

Play Video

Summary of Work Done

Created a 3D third person shooter game based on single player-controlled tank and AI enemies.
Implemented a Transform hierarchy system to enable easier generation of model matrices for child components.
Implemented a forward rendering path.
Implemented a swarm based AI with flocking behaviors.
Implemented an instrumented profiler to keep track frame times and performance.
Implemented a multi-threaded logging system that writes log files to disk.
Implemented a terrain system that chunks the map into smaller parts to enable lighting over different parts of the terrain.
Implemented 3D Raymarching techniques to enable Ray-AABB3, Ray-Sphere, Ray-Terrain intersections.
Implemented a surface patch rendering system that uses height maps to generate scalable terrain.
Implemented a stack-based game state system to enable easy switching and modularized game states.
Implemented a sky-box in OpenGL.

Shadow Mapping

We implemented a basic shadow mapping system that works for a directional light in the scene. We extended our forward rendering path to create shadow maps before the actual render of the scene. The halo around each object is caused by the depth bias.

Forward Render (C++ Snippet)

Shadow Frag Shader (GLSL Snippet)

Forward Render (C++ Snippet)

//-----------------------------------------------------------------------------------------------
// Renders the shadow casting objects for the given light
//
void ForwardRenderPath::RenderShadowObjectForLight(Light* light, RenderScene* scene)
{
	m_shadowCamera->SetOrtho(-128.f, 128.f, -128.f, 128.f, 0.f, 100.f);
	
	Vector3 worldPos = light->GetWorldPosition();

	m_shadowCamera->LookAt(worldPos, worldPos + light->m_transform->GetForward());

	Renderer* rend = Renderer::GetInstance();
	rend->SetCamera(m_shadowCamera);
	rend->ClearDepth();
	rend->ClearScreen(Rgba::BLACK);
	Matrix44 VP = m_shadowCamera->m_projMatrix * m_shadowCamera->m_viewMatrix;
	light->SetViewProjection(VP);

	rend->SetMaterial(rend->CreateOrGetMaterial("Data/Materials/shadow.mat"));
	for(Renderable* renderable : scene->m_renderables)
	{
		if(renderable->IsOpaque())
		{
			rend->DrawMesh(renderable->GetMesh(), renderable->GetModelMatrix());
		}
	}

	rend->ResetDefaultMaterial();
}

Shadow Frag Shader (GLSL Snippet)

float CalculateShadowFactor(vec3 pos, vec3 normal, Light light)
{
   if(light.isShadowCasting == 0.0f)
   {
      return 1.0f;
   }
   float bias_factor = max( dot( light.direction, normal ), 0.0f ); 
   bias_factor = sqrt(1 - (bias_factor * bias_factor)); 
   pos -= light.direction * bias_factor * .25f; 
   
   vec4 clip = light.shadowVP * vec4(pos, 1.0f);
   vec3 ndc = clip.xyz / clip.w;
   vec3 uvd = (ndc.xyz + vec3(1.0f)) * 0.5f;

   float shadowDepth = texture(gShadowMap, uvd).r;

   float min_uv = min( uvd.x, uvd.y ); 
   float max_uv = max( uvd.x, uvd.y ); 
   float blend = 1.0f - min( smoothstep(0.0f, .05f, min_uv), smoothstep(1.0, .95, max_uv) ); 

   // scale by shadow amount
   return mix( light.isShadowCasting * shadowDepth, 1.0f, blend );  
}

Instrumented Profiler

Getting into more terrain generation and tasking operations like flocking behaviors meant I needed to keep track of our frame times to enable smooth frame rates during gameplay. To enable us to keep track of performance, I worked on implementing an instrumented profiler system that’s easy to use during development. I hooked it up to my developer console and it was good to go. I started understanding were my time was being lost and tried to work on some improvements based on that. The profiler UI uses a widget-based system to enable easy iteration for UI elements.

Profiler.h

Profiler.cpp

Profiler.h

#pragma once
#include "Engine/Profiler/ProfilerSample.hpp"
#include "Engine/Profiler/ProfileLogScope.hpp"
#include "Engine/Enumerations/ReportType.hpp"
#include "Engine/Enumerations/ReportSortMode.hpp"

//-----------------------------------------------------------------------------------------------
// Forward Declarations
class Command;
class ProfilerReport;
class Canvas;
class Widget_Textbox;
class Widget_AreaGraph;
enum MouseButton;

//-----------------------------------------------------------------------------------------------
class Profiler
{
public:
	//-----------------------------------------------------------------------------------------------
	// Constructors/Destructors
	Profiler();
	~Profiler();
	
	//-----------------------------------------------------------------------------------------------
	// Accessors/Mutators
			ProfilerSample*					        GetTop() const;
	const	        ProfilerSample*					        GetPreviousFrame( int skipCount = 0 ) const;
			ProfilerSample*					        GetPreviousFrame( int skipCount = 0 );
			bool							IsPaused() const;
			bool							IsProfilerOpen() const;

	//-----------------------------------------------------------------------------------------------
	// Methods
			void							PushProfile( char id[] );
			void							PopProfile();
			ProfilerSample*					        CreateSample( char id[] );
			void							StartProfileFrame();
			void							PauseProfiler();
			void							ResumeProfiler();
			std::vector<ProfilerSample*>	                        GetOrderedPreviousFrames();
			void							Update( float deltaSeconds );
			void							UpdateReportBoxText();
			void							UpdateStatusBoxText();
			void							UpdateControlsBoxText();
			void							UpdateGraphBoxValues();
			void							Render() const;
			void							PrintLastFrameToConsole( ReportType type );
			void							ClearReports();
			void							ProcessInput();
			void							ProcessMouseInput();

	//-----------------------------------------------------------------------------------------------
	// Static Methods
	static	Profiler*						CreateInstance();
	static	void							DestroyInstance();
	static	Profiler*						GetInstance();
	static	void							Push( char id[] );
	static	void							Pop();
	static	void							MarkFrame();
	static	void							Close();
	static	void							Open(); 
	
	//-----------------------------------------------------------------------------------------------
	// Click Listeners
	static	void							CPUGraphClickListener( int selectedIndex, MouseButton buttonCode );

	//-----------------------------------------------------------------------------------------------
	// Command Callbacks
	static	bool							PauseProfilerCommand( Command& cmd );
	static	bool							ResumeProfilerCommand( Command& cmd );
	static	bool							ProfilerCommand( Command& cmd );
	static	bool							ProfilerReportCommand( Command& cmd );

	//-----------------------------------------------------------------------------------------------
	// Members
			ProfilerSample*					m_activeNode = nullptr;
			std::vector<ProfilerSample*>	                m_prevStacks;
			unsigned int					m_prevFrameIndex = 0;
			bool						m_isReadyToPause = false;
			bool						m_isReadyToResume = false;
			bool						m_isPaused = false;
			bool						m_isProfilerOpen = false;
			Canvas*						m_canvas;
			std::vector<ProfilerReport*>	                m_reports;
			Widget_Textbox*					m_statusBoxRef;
			Widget_Textbox*					m_controlsBoxRef;
			Widget_Textbox*					m_reportBoxRef;
			Widget_AreaGraph*				m_graphBoxRef;
			ReportType					m_reportViewType = REPORT_TYPE_TREE;
			bool						m_hasMouseControl = false;
			ReportSortMode					m_reportSortMode = SORT_BY_NONE;
			int						m_selectedFrame = 0;
};

//-----------------------------------------------------------------------------------------------
// Standalone functions
void	ProfilerStartup();
void	ProfilerShutdown();

//-----------------------------------------------------------------------------------------------
// PROFILER MACROS
#define PROFILE_LOG_SCOPE(tag)	ProfileLogScope __timer_ ##__LINE__ ## (tag);
#define PROFILE_LOG_SCOPE_FUNCTION()		PROFILE_LOG_SCOPE(__FUNCTION__);

Profiler.cpp

#include "Engine/Profiler/Profiler.hpp"
//-----------------------------------------------------------------------------------------------
// Engine Includes
#include "Engine/Core/ErrorWarningAssert.hpp"
#include "Engine/Core/EngineCommon.hpp"
#include "Engine/Core/EngineConfig.hpp"
#include "Engine/Math/MathUtils.hpp"
#include "Engine/Console/CommandDefinition.hpp"
#include "Engine/Profiler/ProfilerReport.hpp"
#include "Engine/Console/Command.hpp"
#include "Engine/Console/DevConsole.hpp"
#include "Engine/UI/Canvas.hpp"
#include "Engine/UI/Widgets/Widget_Textbox.hpp"
#include "Engine/UI/Widgets/Widget_AreaGraph.hpp"
#include "Engine/Core/Clock.hpp"
#include "Engine/Input/InputSystem.hpp"
//-----------------------------------------------------------------------------------------------

//-----------------------------------------------------------------------------------------------
// Static globals
static Profiler* g_profiler = nullptr;

#if defined(ENGINE_ENABLE_PROFILING)
//-----------------------------------------------------------------------------------------------
// Constructor
//
Profiler::Profiler()
{
	m_prevStacks.resize(PROFILER_HISTORY_SIZE);
	
	m_canvas = new Canvas();
	m_reportBoxRef = m_canvas->AddTextBox("reportBox", Vector2::ZERO, Vector2(1.f, 0.7f), "test");
	m_controlsBoxRef = m_canvas->AddTextBox("controlsBox", Vector2(0.f, 0.72f), Vector2(0.4f, 0.82f), "controlsBox");
	m_statusBoxRef = m_canvas->AddTextBox("statusBox", Vector2(0.f, 0.84f), Vector2(0.4f, 0.94f), "statusBox");
	
	m_graphBoxRef = m_canvas->AddAreaGraph("usageGraph", Vector2(0.5f, 0.72f), Vector2(1.f, 0.94f), {});
	m_graphBoxRef->SetOnClick(CPUGraphClickListener);
	m_graphBoxRef->SetThresholds(18.f, 22.f); // FPS: 55, 45

	COMMAND("profiler_pause", PauseProfilerCommand, "Pauses the profiler if running");
	COMMAND("profiler_resume", ResumeProfilerCommand, "Resumes the profiler if paused");
	COMMAND("profiler", ProfilerCommand, "Shows the profiler view");
	COMMAND("profiler_report", ProfilerReportCommand, "Prints last frame report to console (tree|flat)");
}

//-----------------------------------------------------------------------------------------------
// Destructor
//
Profiler::~Profiler()
{
	delete m_canvas;
	m_canvas = nullptr;

	ClearReports();

	for(ProfilerSample* sample : m_prevStacks)
	{
		delete sample;
		sample = nullptr;
	}
	m_prevStacks.clear();

	if(m_activeNode)
	{
		delete m_activeNode;
		m_activeNode = nullptr;
	}
}

//-----------------------------------------------------------------------------------------------
// Creates a sample and pushes it to the stack
//
void Profiler::PushProfile(char id[])
{
	if(m_isPaused)
	{
		return;
	}

	ProfilerSample* sample = CreateSample(id);

	if(m_activeNode == nullptr)
	{
		m_activeNode = sample;
	}
	else
	{
		sample->parent = m_activeNode;
		m_activeNode->AddChild(sample);
		m_activeNode = sample;
	}
}

//-----------------------------------------------------------------------------------------------
// Pops the stack 
//
void Profiler::PopProfile()
{
	if(m_isPaused)
	{
		return; 
	}

	GUARANTEE_OR_DIE(m_activeNode != nullptr, "Called Pop without push");

	m_activeNode->Finish();
	m_activeNode = m_activeNode->parent;
}

//-----------------------------------------------------------------------------------------------
// Pops the profiler stack
//
STATIC void Profiler::Pop()
{
	g_profiler->PopProfile();
}

//-----------------------------------------------------------------------------------------------
// Marks the frame start in the profiler
//
void Profiler::MarkFrame()
{
	g_profiler->StartProfileFrame();
}

//-----------------------------------------------------------------------------------------------
// Closes the profiler screen
//
void Profiler::Close()
{
	g_profiler->m_isProfilerOpen = false;
}

//-----------------------------------------------------------------------------------------------
// Opens the profiler screen
//
void Profiler::Open()
{
	g_profiler->m_isProfilerOpen = true;
}

//-----------------------------------------------------------------------------------------------
// Handles click input when the user clicks on the graph
//
void Profiler::CPUGraphClickListener(int selectedIndex, MouseButton buttonCode)
{
	switch (buttonCode)
	{
	case MOUSE_LMB:
		g_profiler->PauseProfiler();
		g_profiler->m_selectedFrame = selectedIndex;
		break;

	case MOUSE_RMB:
		g_profiler->ResumeProfiler();
		g_profiler->m_selectedFrame = 0;
		break;
	}
}

//-----------------------------------------------------------------------------------------------
// Console command to pause profiler
//
bool Profiler::PauseProfilerCommand(Command& cmd)
{
	g_profiler->PauseProfiler();

	UNUSED(cmd);
	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to resume profiler
//
bool Profiler::ResumeProfilerCommand(Command& cmd)
{
	g_profiler->ResumeProfiler();

	UNUSED(cmd);
	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to view the profiler reports
//
bool Profiler::ProfilerCommand(Command& cmd)
{
	if(g_profiler->IsProfilerOpen())
	{
		g_profiler->Close();
	}
	else
	{
		g_profiler->Open();
	}

	UNUSED(cmd);
	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to print the last frame's report
//
bool Profiler::ProfilerReportCommand(Command& cmd)
{
	std::string reportType = cmd.GetNextString();

	if(reportType == "tree" || reportType == "")
	{
		g_profiler->PrintLastFrameToConsole(REPORT_TYPE_TREE);
	}
	else if(reportType == "flat")
	{
		g_profiler->PrintLastFrameToConsole(REPORT_TYPE_FLAT);
	}
	else
	{
		ConsolePrintf("'%s' Unsupported report type", reportType.c_str());
		return false;
	}

	return true;
}

//-----------------------------------------------------------------------------------------------
// Creates a sample and returns it
//
ProfilerSample* Profiler::CreateSample(char id[])
{
	ProfilerSample* sample = new ProfilerSample(id);
	return sample;
}

//-----------------------------------------------------------------------------------------------
// Marks the start of a frame
//
void Profiler::StartProfileFrame()
{
	if(m_activeNode != nullptr)
	{
		if(m_prevStacks[m_prevFrameIndex] != nullptr)
		{
			delete m_prevStacks[m_prevFrameIndex];
		}
		m_prevStacks[m_prevFrameIndex] = m_activeNode;
		PopProfile();
		m_prevFrameIndex = (m_prevFrameIndex + 1) % PROFILER_HISTORY_SIZE;
	
		GUARANTEE_OR_DIE(m_activeNode == nullptr, "Pushed without popping");
	}

	if(m_isReadyToPause)
	{
		m_isPaused = true;
		m_isReadyToPause = false;
		return;
	}

	if(m_isReadyToResume)
	{
		m_isPaused = false;
		m_isReadyToResume = false;
	}

	PushProfile(PROFILER_START_FRAME_TEXT);
}

//-----------------------------------------------------------------------------------------------
// Pauses the profiler 
//
void Profiler::PauseProfiler()
{
	m_isReadyToPause = true;
	m_isReadyToResume = false;
}

//-----------------------------------------------------------------------------------------------
// Resumes the profiler
//
void Profiler::ResumeProfiler()
{
	m_isReadyToPause = false;
	m_isReadyToResume = true;
}

//-----------------------------------------------------------------------------------------------
// Returns the previous frame trees in order. Most recent frame at 0
//
std::vector<ProfilerSample*> Profiler::GetOrderedPreviousFrames() 
{
	std::vector<ProfilerSample*> frames(PROFILER_HISTORY_SIZE);

	int frameIndex = 0;
	for(int orderIndex = PROFILER_HISTORY_SIZE - 1; orderIndex >= 0; --orderIndex)
	{
		ProfilerSample* sample = GetPreviousFrame(frameIndex);
		frames[orderIndex] = sample;
		frameIndex++;
	}

	return frames;
}

//-----------------------------------------------------------------------------------------------
// Updates the profiler view if its open
//
void Profiler::Update(float deltaSeconds)
{
	if(!m_isProfilerOpen)
	{
		return; // No need to generate/update reports if the profiler is closed
	}

	ProcessInput();
	ProcessMouseInput();

	UpdateReportBoxText();
	UpdateStatusBoxText();
	UpdateControlsBoxText();
	UpdateGraphBoxValues();
	m_canvas->Update(deltaSeconds);

	UNUSED(deltaSeconds);
}

//-----------------------------------------------------------------------------------------------
// Updates the report text box with the formatted string
//
void Profiler::UpdateReportBoxText()
{
	ClearReports();

	// Most recent frame is at 0
	std::vector<ProfilerSample*> prevFrames = GetOrderedPreviousFrames();

	for(ProfilerSample* sample : prevFrames)
	{
		if(sample == nullptr)
		{
			break;
		}

		ProfilerReport* report = new ProfilerReport();

		switch (m_reportViewType)
		{
		case REPORT_TYPE_FLAT:
			report->GenerateFlatFromFrame(sample);
			break;
		case REPORT_TYPE_TREE:
			report->GenerateTreeFromFrame(sample);
			break;
		default:
			GUARANTEE_OR_DIE(false, "Wrong report frame type");
			break;
		}
		
		switch (m_reportSortMode)
		{
		case SORT_BY_NONE:			/* DO NOTHING */ 				break;
		case SORT_BY_TOTAL_TIME:	report->SortByTotalTime();		break;
		case SORT_BY_SELF_TIME:		report->SortBySelfTime(); 		break;
		default:
			GUARANTEE_OR_DIE(false, "Bad report sort mode");
			break;
		}

		m_reports.push_back(report);
	}

	ProfilerReport* report = m_reports[m_selectedFrame];
	m_reportBoxRef->SetText(report->GetFormattedString());
}

//-----------------------------------------------------------------------------------------------
// Updates the status box text widget
//
void Profiler::UpdateStatusBoxText()
{
	double frameTime = m_reports[m_selectedFrame]->GetTotalFrameTime();
	double fps = 0.0;

	if(m_isPaused)
	{
		fps = 1.0 / frameTime;
	}
	else
	{
		for(int index = 0; index < 60; ++index) // Assuming 60 frames a second to get the average value
		{
			fps += m_reports[index]->GetTotalFrameTime();
		}

		fps = 60.0 * 1.0 / fps;
	}
	
	std::string fpsString = Stringf("FPS: %0.2f", fps) + "\n";
	std::string frameTimeStr = Stringf("Frame Time: %0.4f ms", frameTime * 1000.0) + "\n";
	m_statusBoxRef->SetText(fpsString + frameTimeStr);
}

//-----------------------------------------------------------------------------------------------
// Updates the controls box text widget
//
void Profiler::UpdateControlsBoxText()
{
	std::string ReportViewText = Stringf("Toggle ReportView [V]: %s\n", m_reportViewType == REPORT_TYPE_TREE ? "TREE VIEW" : "FLAT VIEW");
	std::string MouseText = Stringf("Enable/Disable Mouse [M]: %s\n", m_hasMouseControl ? "Enabled" : "Disabled");

	std::string sortModeStr;
	switch (m_reportSortMode)
	{
	case SORT_BY_NONE:			sortModeStr = "NONE";		break;
	case SORT_BY_TOTAL_TIME:	sortModeStr = "TOTAL TIME"; break;
	case SORT_BY_SELF_TIME:		sortModeStr = "SELF TIME";	break;
	default:					sortModeStr = "BAD STRING";	break;	
	}

	std::string SortText = Stringf("Toggle Sort modes [L]: %s \n", sortModeStr.c_str());
	std::string controlsText =  ReportViewText + MouseText + SortText;
	m_controlsBoxRef->SetText(controlsText);
}

//-----------------------------------------------------------------------------------------------
// Updates the graph values on the graph widget
//
void Profiler::UpdateGraphBoxValues()
{
	std::vector<float> timeValues(PROFILER_HISTORY_SIZE);

	for(int index = 0; index < PROFILER_HISTORY_SIZE; ++index)
	{
		timeValues[index] = (float) m_reports[index]->GetTotalFrameTime() * 1000.f;
	}

	m_graphBoxRef->SetValues(timeValues);
}

//-----------------------------------------------------------------------------------------------
// Renders the profiler report
//
void Profiler::Render() const
{
	if(!m_isProfilerOpen)
	{
		return; // No need to show reports if the profiler is closed
	}

	m_canvas->Render();
}

//-----------------------------------------------------------------------------------------------
// Prints the last frame's report to console
//
void Profiler::PrintLastFrameToConsole(ReportType type)
{
	ProfilerReport report;
	ProfilerSample* prevFrame = GetPreviousFrame(0);
	switch (type)
	{
	case REPORT_TYPE_FLAT:
		report.GenerateFlatFromFrame(prevFrame);
		report.PrintReportToConsole();
		break;

	case REPORT_TYPE_TREE:
		report.GenerateTreeFromFrame(prevFrame);
		report.PrintReportToConsole();
		break;

	default:
		GUARANTEE_OR_DIE(false, "Unsupported report type");
	}
}

//-----------------------------------------------------------------------------------------------
// Destroys the reports
//
void Profiler::ClearReports()
{
	for(ProfilerReport* report : m_reports)
	{
		delete report;
	}

	m_reports.clear();
}

//-----------------------------------------------------------------------------------------------
// Processes input keys
//
void Profiler::ProcessInput()
{
	InputSystem* input = InputSystem::GetInstance();
	
	if(input->WasKeyJustPressed(KEYCODE_V))
	{
		m_reportViewType = (ReportType) ((m_reportViewType + 1) % NUM_REPORT_TYPES);
	}

	if(input->WasKeyJustPressed(KEYCODE_L))
	{
		m_reportSortMode = (ReportSortMode) ((m_reportSortMode + 1) % NUM_SORT_MODES);
	}

	if(input->WasKeyJustPressed(KEYCODE_M))
	{
		
		m_hasMouseControl = !m_hasMouseControl;
		m_canvas->SetMouseInput(m_hasMouseControl);
		if(m_hasMouseControl)
		{
			InputSystem::LockMouseToWindow(false);
			InputSystem::ShowCursor(true);
			InputSystem::GetInstance()->SetMouseMode(MOUSE_ABSOLUTE);
		}
		else
		{
			InputSystem::LockMouseToWindow(true);
			InputSystem::ShowCursor(false);
			InputSystem::GetInstance()->SetMouseMode(MOUSE_RELATIVE);
		}
	}
}

//-----------------------------------------------------------------------------------------------
// Processes mouse inputs if the profiler has control 
//
void Profiler::ProcessMouseInput()
{

}

//-----------------------------------------------------------------------------------------------
// Returns the top node
// 
ProfilerSample* Profiler::GetTop() const
{
	return m_activeNode;
}

//-----------------------------------------------------------------------------------------------
// Returns true if the profiler is paused
// 
bool Profiler::IsPaused() const
{
	return m_isPaused;
}

//-----------------------------------------------------------------------------------------------
// Returns true if the profiler is open
// 
bool Profiler::IsProfilerOpen() const
{
	return m_isProfilerOpen;
}

//-----------------------------------------------------------------------------------------------
// Returns the n-th previous frame, 0 meaning immediate previous
//
ProfilerSample* Profiler::GetPreviousFrame(int skipCount /*= 0 */)
{
	if(m_prevStacks.size() <= 0 && skipCount >= 0)
	{
		return nullptr; 
	}

	int actualIndex = ((int) m_prevFrameIndex - 1) - skipCount;
	actualIndex = ( PROFILER_HISTORY_SIZE + ( actualIndex % PROFILER_HISTORY_SIZE ) ) % PROFILER_HISTORY_SIZE;
	return m_prevStacks[actualIndex];
}

//-----------------------------------------------------------------------------------------------
// Returns the n-th previous frame, 0 meaning immediate previous
//
const ProfilerSample* Profiler::GetPreviousFrame(int skipCount /*= 0 */) const
{
	if(m_prevStacks.size() <= 0 && skipCount >= 0)
	{
		return nullptr; 
	}

	skipCount = ClampInt(skipCount, 0, PROFILER_HISTORY_SIZE);
	int actualIndex = ((int) m_prevFrameIndex - 1) - skipCount;
	if(actualIndex < 0)
	{
		actualIndex = PROFILER_HISTORY_SIZE - skipCount;
	}

	return m_prevStacks[actualIndex];
}

//-----------------------------------------------------------------------------------------------
// Creates the instance 
//
STATIC Profiler* Profiler::CreateInstance()
{
	if(!g_profiler)
	{
		g_profiler = new Profiler();
	}

	return g_profiler;
}

//-----------------------------------------------------------------------------------------------
// Destroys the instance
//
STATIC void Profiler::DestroyInstance()
{
	delete g_profiler;
	g_profiler = nullptr;
}

//-----------------------------------------------------------------------------------------------
// Returns the instance
//
STATIC Profiler* Profiler::GetInstance()
{
	return g_profiler;
}

//-----------------------------------------------------------------------------------------------
// Pushes a new sample
//
STATIC void Profiler::Push(char id[])
{
	g_profiler->PushProfile(id);
}

//-----------------------------------------------------------------------------------------------
// Starts up the profiler
//
void ProfilerStartup()
{
	Profiler::CreateInstance();
}

//-----------------------------------------------------------------------------------------------
// Shuts down the profiler
//
void ProfilerShutdown()
{
	Profiler::DestroyInstance();
}

#else
#pragma warning(disable:4100)
		ProfilerSample*					Profiler::GetTop() const { return nullptr; }
		const	ProfilerSample*			Profiler::GetPreviousFrame( int skipCount ) const{ return nullptr; }
		ProfilerSample*					Profiler::GetPreviousFrame( int skipCount ) { return nullptr; }
		bool							Profiler::IsPaused() const { return false; }
		bool							Profiler::IsProfilerOpen() const { return false; }
		
		std::vector<ProfilerSample*>	Profiler::GetOrderedPreviousFrames(){ return {}; }
		void							Profiler::UpdateReportBoxText(){}
		void							Profiler::UpdateStatusBoxText( float deltaSeconds ) {}
		void							Profiler::UpdateControlsBoxText() {}
		void							Profiler::UpdateGraphBoxValues() {}
		void							Profiler::PrintLastFrameToConsole( ReportType type ){}
		void							Profiler::ClearReports() {}
		void							Profiler::ProcessInput(){}
		void							Profiler::ProcessMouseInput() {}
		void							Profiler::PushProfile( char id[] ) {}
		void							Profiler::PopProfile() {}
		ProfilerSample*					Profiler::CreateSample( char id[] ) { return nullptr; }
		void							Profiler::StartProfileFrame() {}
		void							Profiler::PauseProfiler() {}
		void							Profiler::ResumeProfiler() {}
		void							Profiler::Update( float deltaSeconds ) {}
		void							Profiler::Render() const {}
		Profiler*						Profiler::CreateInstance() { return nullptr; }
		void							Profiler::DestroyInstance() {}
		Profiler*						Profiler::GetInstance() {  return nullptr; }
		void							Profiler::Push( char id[] ) {}
		void							Profiler::Pop() {}
		void							Profiler::MarkFrame() {}
		bool							Profiler::PauseProfilerCommand( Command& cmd ) { return false; }
		bool							Profiler::ResumeProfilerCommand( Command& cmd ) { return false; }
		void							Profiler::CPUGraphClickListener( int selectedIndex, MouseButton buttonCode ) {}

		void							ProfilerStartup() {}
		void							ProfilerShutdown() {}

#endif // ENABLE_ENGINE_PROFILING

Threaded Logging System

Moving into networking meant we needed some form of logging system that would enable us to debug engine systems and network packets.

Logger.h

Logger.cpp

Loglog_20180716_073052.txt (Example)

Logger.h

#pragma once
#include "Engine/Async/ThreadSafeQueue.hpp"
#include 
#include "Engine/Async/ThreadSafeVector.hpp"

//-----------------------------------------------------------------------------------------------
// Forward Declarations
class Command;

//-----------------------------------------------------------------------------------------------
// Macros
constexpr char* DEFAULT_LOG_TAG = "log";
constexpr char* DEFAULT_WARNING_TAG = "warning";
constexpr char* DEFAULT_ERROR_TAG = "error";

//-----------------------------------------------------------------------------------------------
struct LogMessage
{
	std::string tag;
	std::string text;
};

typedef void (*LogCb)( const LogMessage& msg, void* userData );

//-----------------------------------------------------------------------------------------------
struct LogHookDef
{
	LogCb callback;
	void* userData;
};

//-----------------------------------------------------------------------------------------------
class Logger
{
public:
	//-----------------------------------------------------------------------------------------------
	// Constructors/Destructors
	Logger();
	~Logger();
	
	//-----------------------------------------------------------------------------------------------
	// Accessors/Mutators
			bool IsRunning() const { return m_isRunning; }

	//-----------------------------------------------------------------------------------------------
	// Methods
			void Start() { m_isRunning = true; }
			void Stop() { m_isRunning = false; }
			void Flush();
			void AddHook( LogHookDef* hook );
			void AddHook( LogCb cb, void* userData );
			void RemoveHook( LogHookDef* hook );
			void RemoveHook( LogCb cb, void* userData );
			void AddLogMessage( LogMessage* msg );
			void AddLogMessage( const std::string& tag, const std::string& text );
			void EnableTag( const char* tag );
			void DisableTag( const char* tag );
			void EnableAll();
			void DisableAll();

	//-----------------------------------------------------------------------------------------------
	// Testing methods
			void Test(const char* fileName, int threadCount );

	//-----------------------------------------------------------------------------------------------
	// Static methods
	static	Logger*	CreateInstance();
	static	Logger*	GetInstance();
	static	void	DestroyInstance();
	static	void	LogThreadWorker( void* userData = nullptr );
	static	void	LogTestWorker( void* userData = nullptr );
	static	void	WriteLogToFile( const LogMessage& msg, void* filePtr );
	
	//-----------------------------------------------------------------------------------------------
	// Command callbacks
	static	bool	FlushTestCommand( Command& cmd );
	static	bool	LogTestCommand( Command& cmd );
	static	bool	LogEnableAllCommand( Command& cmd );
	static	bool	LogDisableAllCommand( Command& cmd );
	static	bool	LogEnableTagCommand( Command& cmd );
	static	bool	LogHideTagCommand( Command& cmd );

	//-----------------------------------------------------------------------------------------------
	// Members
	bool							m_isRunning = true;
	void*							m_thread;
	ThreadSafeQueue<LogMessage*>	m_logQueue;
	ThreadSafeVector<LogHookDef*>	m_hooks;
	ThreadSafeVector<std::string>	m_filters;
	bool							m_areFiltersWhiteList = false;
};

//-----------------------------------------------------------------------------------------------
// Standalone functions

// System Functions
void LogSystemStartup( const char* fileName = DEFAULT_LOG_TAG ); // Do not include extension in filename
void LogSystemShutdown();

// Logger functions
void LogTaggedPrintv( const char* tag, const char* format, va_list args );
void LogFlush();

// Logger Helpers
void LogTaggedPrintf( const char* tag, const char* format, ... );
void LogPrintf( const char* format, ... ); // Defaults to log tag 
void LogWarningf( const char* format, ... ); // Defaults to warning tag
void LogErrorf( const char* format, ... ); // Defaults to error tag. Flush and then assert at the end

// Filtering functions
void LogShowAll();
void LogHideAll();
void LogShowTag( const char* tag );
void LogHideTag( const char* tag );

// Hooking
void LogHook( LogCb cb, void* userData = nullptr );
void LogUnhook( LogCb cb, void* userData = nullptr );

Logger.cpp

#include "Engine/Logger/Logger.hpp"
//-----------------------------------------------------------------------------------------------
// Engine Includes
#include "Engine/Async/Thread.hpp"
#include "Engine/Core/EngineCommon.hpp"
#include "Engine/Core/Time.hpp"
#include "Engine/File/File.hpp"
#include "Engine/Core/ErrorWarningAssert.hpp"
#include "Engine/Console/CommandDefinition.hpp"
#include "Engine/Console/Command.hpp"
#include "Engine/Core/StringTokenizer.hpp"
#include "Engine/Console/DevConsole.hpp"
#include "Engine/Core/Platform/Win32.hpp"
//-----------------------------------------------------------------------------------------------

//-----------------------------------------------------------------------------------------------
// Static globals
static Logger*	s_logger = nullptr;
static File*	s_timeStampedLog = nullptr;
static File*	s_logFile = nullptr;

//-----------------------------------------------------------------------------------------------
// Starts up the logger system and timestamps the fileName
//
void LogSystemStartup(const char* fileName /*= DEFAULT_LOG_TAG */)
{
	Logger::CreateInstance();
	s_logger->m_thread = ThreadCreate("Logger Thread", s_logger->LogThreadWorker, nullptr);

	std::string logFileName = "Log/";
	logFileName += fileName;
	
	std::string defaultLogFile = logFileName + ".txt";

	// Creates the directory if it's not available
	if(!CreateDirectoryA("Log/", NULL)) 
	{
	}

	s_logFile = new File();
	int errorCode2 = s_logFile->Open(defaultLogFile.c_str(), FILE_WRITE); // Default log file

	//YYYYMMDD_HHMMSS
	std::string timeStamp = Time::GetSysTimeStamp();
	logFileName = logFileName + "_" + timeStamp + ".txt"; // Append the time stamp onto the fileName

	s_timeStampedLog = new File();
	int errorCode = s_timeStampedLog->Open(logFileName.c_str(), FILE_WRITE);

	
	if(errorCode != 0 && errorCode2 != 0) // fopen error codes
	{
		GUARANTEE_OR_DIE(false, "Couldn't create log file");
		delete s_timeStampedLog;
		s_timeStampedLog = nullptr;

		delete s_logFile;
		s_logFile = nullptr;
	}

	LogHook(Logger::WriteLogToFile, s_timeStampedLog);
	LogHook(PrintToIDE, nullptr);
}

//-----------------------------------------------------------------------------------------------
// Shutsdown the logger system 
//
void LogSystemShutdown()
{
	s_logger->Stop();
	ThreadJoin((ThreadHandle) s_logger->m_thread);
	
	s_logger->m_thread = nullptr;
	Logger::DestroyInstance();

	if(s_timeStampedLog != nullptr)
	{
		s_timeStampedLog->Close();
		delete s_timeStampedLog;
		s_timeStampedLog = nullptr;
	}
}

//-----------------------------------------------------------------------------------------------
// Constructor
//
Logger::Logger()
{
	COMMAND("logflushtest", FlushTestCommand, "Tests the log flush utility");
	COMMAND("logtest", LogTestCommand, "Threaded logger stress test");
	COMMAND("logenableall", LogEnableAllCommand, "Enables all tags for logging");
	COMMAND("logdisableall", LogDisableAllCommand,"Disables all tags for logging");
	COMMAND("logshowtag", LogEnableTagCommand, "Enables a single tag for logging");
	COMMAND("loghidetag", LogHideTagCommand, "Hides a single tag during logging");
	DisableTag("debug");

}

//-----------------------------------------------------------------------------------------------
// Destructor
//
Logger::~Logger()
{
	Flush();
}

//-----------------------------------------------------------------------------------------------
// Writes the message to the log file (Thread Safe)
//
void Logger::WriteLogToFile(const LogMessage& msg, void* filePtr)
{
	File* fp = (File*) filePtr;
	fp->Printf("%s: %s", msg.tag.c_str(), msg.text.c_str());
}

//-----------------------------------------------------------------------------------------------
// Command callback to test log flush utility
//
bool Logger::FlushTestCommand(Command& cmd)
{
	LogPrintf("LogFlushTest");
	LogFlush();

	UNUSED(cmd);
	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to test the logger
//
bool Logger::LogTestCommand(Command& cmd)
{

	std::string fileName = cmd.GetNextString();

	int threadCount;
	if(!cmd.GetNextInt(threadCount))
	{
		threadCount = 1;
	}

	s_logger->Test(fileName.c_str(), threadCount);

	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to enable all tags
//
bool Logger::LogEnableAllCommand(Command& cmd)
{
	UNUSED(cmd);
	LogShowAll();

	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to disable all tags 
//
bool Logger::LogDisableAllCommand(Command& cmd)
{
	UNUSED(cmd);
	LogHideAll();

	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to enable a single tag
//
bool Logger::LogEnableTagCommand(Command& cmd)
{
	std::string tag = cmd.GetNextString();
	LogShowTag(tag.c_str());

	return true;
}

//-----------------------------------------------------------------------------------------------
// Console command to hide a single tag
//
bool Logger::LogHideTagCommand(Command& cmd)
{
	std::string tag = cmd.GetNextString();
	LogHideTag(tag.c_str());

	return true;
}

//-----------------------------------------------------------------------------------------------
// Will ensure that before returning, all currently in flight log messages are complete, 
// and the file IO operations have been flushed
//
void Logger::Flush()
{
	LogMessage* msg;
	while(m_logQueue.Dequeue(&msg))
	{
		if((m_filters.Find(msg->tag) != UINT32_MAX) ^ m_areFiltersWhiteList)
		{
			delete msg; // Cleanup
			continue; // Filter found 
		}

		for(size_t index = 0; index < m_hooks.Size(); ++index)
		{
			m_hooks[index]->callback(*msg, m_hooks[index]->userData);
		}

		delete msg; // Cleanup
	}
}

//-----------------------------------------------------------------------------------------------
// Adds a hook to the list of hooks 
//
void Logger::AddHook(LogHookDef* hook)
{
	m_hooks.PushBack(hook);
}

//-----------------------------------------------------------------------------------------------
// Adds a hook to the list of hooks
//
void Logger::AddHook(LogCb cb, void* userData)
{
	LogHookDef* hook = new LogHookDef();
	hook->callback = cb;
	hook->userData = userData;

	AddHook(hook);
}

//-----------------------------------------------------------------------------------------------
// Removes a hook from the list of hooks
//
void Logger::RemoveHook(LogHookDef* hook)
{
	RemoveHook(hook->callback, hook->userData);
}

//-----------------------------------------------------------------------------------------------
// Removes the hook from the list of hooks that is identified by the callback and userdata
//
void Logger::RemoveHook(LogCb cb, void* userData)
{
	for(size_t index = 0; index < m_hooks.Size(); ++index)
	{
		if(m_hooks[index]->callback == cb && m_hooks[index]->userData == userData)
		{
			m_hooks.Erase(index);
			break;
		}
	}
}

//-----------------------------------------------------------------------------------------------
// Adds a log message to the queue
//
void Logger::AddLogMessage(const std::string& tag, const std::string& text)
{
	LogMessage* msg = new LogMessage();
	msg->tag = tag;
	msg->text = text;

	AddLogMessage(msg);
}

//-----------------------------------------------------------------------------------------------
// Adds a log message to the queue
//
void Logger::AddLogMessage(LogMessage* msg)
{
	m_logQueue.Enqueue(msg);
}

//-----------------------------------------------------------------------------------------------
// If blacklist, tag is removed. If whitelist, tag is added
//
void Logger::EnableTag(const char* tag)
{
	if(m_areFiltersWhiteList == false)
	{
		m_filters.Erase(tag);
	}
	else
	{
		m_filters.PushBack(tag);
	}
}

//-----------------------------------------------------------------------------------------------
// If whitelist, tag is added. If blacklist, tag is removed
//
void Logger::DisableTag(const char* tag)
{
	if(m_areFiltersWhiteList)
	{
		m_filters.Erase(tag);
	}
	else
	{
		m_filters.PushBack(tag);
	}
}

//-----------------------------------------------------------------------------------------------
// Switches the filters to blacklist
//
void Logger::EnableAll()
{
	m_filters.Clear();
	m_areFiltersWhiteList = false;
}

//-----------------------------------------------------------------------------------------------
// Switches the filters to whitelist
//
void Logger::DisableAll()
{
	m_filters.Clear();
	m_areFiltersWhiteList = true;
}

//-----------------------------------------------------------------------------------------------
// Tests logger by spinning up threads that will read a file and log it
//
void Logger::Test(const char* fileName, int threadCount)
{
	size_t fileNameLength = strlen(fileName);

	// Spin up threads 
	while(threadCount > 0)
	{
		char* nameCopy = new char[fileNameLength + 1];
		memcpy(nameCopy, fileName, fileNameLength);
		nameCopy[fileNameLength] = '\0';

		ThreadCreateAndDetach(LogTestWorker, (void*) nameCopy);

		threadCount--;
	}
}

//-----------------------------------------------------------------------------------------------
// Creates the logger instance and returns a reference
//
Logger* Logger::CreateInstance()
{
	if(!s_logger)
	{
		s_logger = new Logger();
	}

	return s_logger;
}

//-----------------------------------------------------------------------------------------------
// Returns the logger instance
//
Logger* Logger::GetInstance()
{
	return s_logger;
}

//-----------------------------------------------------------------------------------------------
// Destroys the logger instance
//
void Logger::DestroyInstance()
{
	delete s_logger;
	s_logger = nullptr;
}

//-----------------------------------------------------------------------------------------------
// Logger thread worker to write into files
//
void Logger::LogThreadWorker(void* userData /*= nullptr */)
{
	Logger* logger = Logger::GetInstance();
	while(logger->IsRunning())
	{
		logger->Flush();
		ThreadSleep(10);
	}

	logger->Flush();

	UNUSED(userData);
}

//-----------------------------------------------------------------------------------------------
// Log test worker thread safe callback. Reads a file and writes to log
//
void Logger::LogTestWorker(void* userData /*= nullptr */)
{
	const char* fileName = (char*) userData;

	// Read the file
	char* fileContents = (char*) FileReadToNewBuffer(fileName);
	size_t threadId = ThreadGetCurrentID();

	// Tokenize into lines
	StringTokenizer tokenizer(fileContents, "\n");
	tokenizer.Tokenize();
	Strings lines = tokenizer.GetTokens();

	// Log each line
	for(size_t lineNum = 0; lineNum < lines.size(); ++lineNum)
	{
		LogTaggedPrintf("logtest", "%d:%d: %s\n", threadId, lineNum, lines[lineNum].c_str());
	}

	LogTaggedPrintf("teststatus", "\n Log Testing success on thread: %d \n", threadId);

	free( (void*) fileName);
	free(fileContents);
}

//-----------------------------------------------------------------------------------------------
// Prints a message with a tag to the log
//
void LogTaggedPrintv(const char* tag, const char* format, va_list args)
{
	const int MAX_LENGTH = 2048;
	char buffer[MAX_LENGTH];

	vsnprintf_s(buffer, MAX_LENGTH, _TRUNCATE, format, args);
	buffer[MAX_LENGTH - 1] = '\0';

	s_logger->AddLogMessage(tag, buffer);
}

//-----------------------------------------------------------------------------------------------
// Flushes the log and writes the log queue to file
//
void LogFlush()
{
	s_logger->Flush();
}

//-----------------------------------------------------------------------------------------------
// Prints a tagged log message to file
//
void LogTaggedPrintf(const char* tag, const char* format, ...)
{
	va_list args;
	va_start(args, format);
	LogTaggedPrintv(tag, format, args);
	va_end(args);
}

//-----------------------------------------------------------------------------------------------
// Prints log message with the default log tag to file
//
void LogPrintf(const char* format, ...)
{
	va_list args;
	va_start(args, format);
	LogTaggedPrintv(DEFAULT_LOG_TAG, format, args);
	va_end(args);
}

//-----------------------------------------------------------------------------------------------
// Prints log message with the warning tag to file
//
void LogWarningf(const char* format, ...)
{
	va_list args;
	va_start(args, format);
	LogTaggedPrintv(DEFAULT_WARNING_TAG, format, args);
	va_end(args);
}

//-----------------------------------------------------------------------------------------------
// Prints log message with the error tag to file
//
void LogErrorf(const char* format, ...)
{
	va_list args;
	va_start(args, format);
	LogTaggedPrintv(DEFAULT_ERROR_TAG, format, args);
	va_end(args);
}

//-----------------------------------------------------------------------------------------------
// Converts the filters to blacklists
//
void LogShowAll()
{
	s_logger->EnableAll();
}

//-----------------------------------------------------------------------------------------------
// Converts the filters to whitelists
//
void LogHideAll()
{
	s_logger->DisableAll();
}

//-----------------------------------------------------------------------------------------------
// if blacklist, tag will be removed. If whitelist, tag will be added
//
void LogShowTag(const char* tag)
{
	s_logger->EnableTag(tag);
}

//-----------------------------------------------------------------------------------------------
// if whitelist, tag will be removed. If blacklist, tag will be added
//
void LogHideTag(const char* tag)
{
	s_logger->DisableTag(tag);
}

//-----------------------------------------------------------------------------------------------
// Hooks into the log system to callback when something is logged
//
void LogHook(LogCb cb, void* userData /*= nullptr */)
{
	s_logger->AddHook(cb, userData);
}

//-----------------------------------------------------------------------------------------------
// Unplugs from the log system
//
void LogUnhook(LogCb cb, void* userData /*= nullptr */)
{
	s_logger->RemoveHook(cb, userData);
}

Loglog_20180716_073052.txt (Example)

debug: 
GL ERROR [0x0500] at [d:\guildhall\p4\c27\students\knappoly\projects\engine\code\engine\renderer\texture.cpp(105)]

debug: 
Reading game configuration from Data/gameconfig.xml
debug: 
Game config loaded successfully.

Postmortem

Easier Than Thought

Harder Than Thought

Hard Takeaways

Soft Takeaways

Easier Than Thought

Harder Than Thought

Hard Takeaways

Soft Takeaways