diff --git a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.cpp b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.cpp index 31c31768..4aee8a30 100644 --- a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.cpp +++ b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.cpp @@ -58,7 +58,12 @@ namespace opengl { m_executed = false; } - +#ifdef GL_DEBUG + std::string OpenGlCommand::getFunctionName() + { + return m_functionName; + } +#endif OpenGlCommand::OpenGlCommand(bool _synced, bool _logIfSynced, const std::string &_functionName, bool _isGlCommand) : m_synced(_synced), m_executed(false) diff --git a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.h b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.h index fd9e1f88..c7820745 100644 --- a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.h +++ b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Command.h @@ -18,6 +18,9 @@ namespace opengl { void performCommand(); void waitOnCommand(); +#ifdef GL_DEBUG + std::string getFunctionName(); +#endif virtual bool isTimeToShutdown(); diff --git a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.cpp b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.cpp index dd9a5b01..30858fd9 100644 --- a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.cpp +++ b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.cpp @@ -2,6 +2,7 @@ #include "opengl_WrappedFunctions.h" #include "Graphics/OpenGLContext/GLFunctions.h" #include +#include namespace opengl { @@ -12,28 +13,50 @@ namespace opengl { std::thread FunctionWrapper::m_commandExecutionThread; std::mutex FunctionWrapper::m_condvarMutex; std::condition_variable FunctionWrapper::m_condition; +#if defined(GL_DEBUG) && defined(GL_PROFILE) + std::map FunctionWrapper::m_functionProfiling; + std::chrono::time_point FunctionWrapper::m_lastProfilingOutput; +#endif BlockingReaderWriterQueue> FunctionWrapper::m_commandQueue; BlockingReaderWriterQueue> FunctionWrapper::m_commandQueueHighPriority; void FunctionWrapper::executeCommand(std::shared_ptr _command) { -#ifndef GL_DEBUG +#if !defined(GL_DEBUG) m_commandQueue.enqueue(_command); _command->waitOnCommand(); -#else +#elif !defined(GL_PROFILE) _command->performCommandSingleThreaded(); +#else + auto callStartTime = std::chrono::high_resolution_clock::now(); + _command->performCommandSingleThreaded(); + std::chrono::duration callDuration = std::chrono::high_resolution_clock::now() - callStartTime; + + ++m_functionProfiling[_command->getFunctionName()].m_callCount; + m_functionProfiling[_command->getFunctionName()].m_totalTime += callDuration.count(); + + logProfilingData(); #endif } void FunctionWrapper::executePriorityCommand(std::shared_ptr _command) { -#ifndef GL_DEBUG +#if !defined(GL_DEBUG) m_commandQueueHighPriority.enqueue(_command); m_commandQueue.enqueue(nullptr); _command->waitOnCommand(); +#elif !defined(GL_PROFILE) + _command->performCommandSingleThreaded(); #else + auto callStartTime = std::chrono::high_resolution_clock::now(); _command->performCommandSingleThreaded(); + std::chrono::duration callDuration = std::chrono::high_resolution_clock::now() - callStartTime; + + ++m_functionProfiling[_command->getFunctionName()].m_callCount; + m_functionProfiling[_command->getFunctionName()].m_totalTime += callDuration.count(); + + logProfilingData(); #endif } @@ -56,11 +79,48 @@ namespace opengl { } } +#if defined(GL_DEBUG) && defined(GL_PROFILE) + void FunctionWrapper::logProfilingData() + { + std::chrono::duration timeSinceLastOutput = std::chrono::high_resolution_clock::now() - m_lastProfilingOutput; + + static const double profilingOutputInterval = 10.0; + if (timeSinceLastOutput.count() > profilingOutputInterval) { + + // Declaring the type of Predicate that accepts 2 pairs and return a bool + typedef std::function, std::pair)> Comparator; + + // Defining a lambda function to compare two pairs. It will compare two pairs using second field + Comparator compFunctor = + [](std::pair elem1, std::pair elem2) + { + return elem1.second.m_totalTime > elem2.second.m_totalTime; + }; + std::set, Comparator> functionSet(m_functionProfiling.begin(), m_functionProfiling.end(), compFunctor); + + LOG(LOG_ERROR, "Profiling output"); + for ( auto element : functionSet ) { + std::stringstream output; + output << element.first << ": call_count=" << element.second.m_callCount + << " duration=" << element.second.m_totalTime + << " average_per_call=" << element.second.m_totalTime/element.second.m_callCount; + LOG(LOG_ERROR, output.str().c_str()); + } + + m_functionProfiling.clear(); + m_lastProfilingOutput = std::chrono::high_resolution_clock::now(); + } + } +#endif + void FunctionWrapper::setThreadedMode(u32 _threaded) { #ifdef GL_DEBUG m_threaded_wrapper = true; m_shutdown = false; +#ifdef GL_PROFILE + m_lastProfilingOutput = std::chrono::high_resolution_clock::now(); +#endif #else if (_threaded == 1) { m_threaded_wrapper = true; diff --git a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.h b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.h index 9e4b74c1..733d57ed 100644 --- a/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.h +++ b/src/Graphics/OpenGLContext/ThreadedOpenGl/opengl_Wrapper.h @@ -5,6 +5,7 @@ #include "opengl_WrappedFunctions.h" #include "opengl_Command.h" #include +#include #ifdef MUPENPLUSAPI #include @@ -34,6 +35,24 @@ namespace opengl { static std::mutex m_condvarMutex; static std::condition_variable m_condition; +#if defined(GL_DEBUG) && defined(GL_PROFILE) + static void logProfilingData(); + + struct FunctionProfilingData + { + double m_totalTime; + int m_callCount; + + FunctionProfilingData() + { + m_totalTime = 0; + m_callCount = 0; + } + }; + static std::map m_functionProfiling; + static std::chrono::time_point m_lastProfilingOutput; +#endif + static const int MAX_SWAP = 2; public: