Added profiler support

Fixed memory leak and CTD with editor summary info Added extra VS2K5 property pages for debug support git-svn-id: https://ja2svn.mooo.com/source/ja2/trunk/GameSource/ja2_v1.13/Build@1528 3b4a5df2-a311-0410-b5c6-a8a6f20db521
2026-07-29 13:52:17 +02:00 · 2007-10-20 06:56:34 +00:00
parent b43ec593fe
commit ea68cd14ff
8 changed files with 620 additions and 21 deletions
@@ -0,0 +1,442 @@
+#ifdef PROFILER_ENABLED
+
+#include "builddefines.h"
+#include <sstream>
+
+#ifdef PERIODIC_PROFILING
+bool gRecordingProfile = false;
+#endif
+
+PerfManager* PerfManager::_instance(NULL);
+
+PerfDatum::PerfDatum(	const char* const fileName, 
+						const char* const functionName,
+						const int lineNumber,
+						__int64 cycles,
+						__int64 calls)
+	:
+	_fileName(fileName),
+	_functionName(functionName),
+	_lineNumber(lineNumber),
+	_cycles(cycles),
+	_calls(calls)
+{
+}
+
+PerfManager::PerfManager(void)
+	:
+	_callTime(0),
+	_totalTime(0)
+{
+	//Set up a root function so that the stack is never empty:
+	//(this will be the only entry with _lineNumber equal to 0)
+	_perfLog.insert(PerfDatum(__FILE__, "Root",0));
+	_perfStack.push_back(&*(_perfLog.begin()));
+	_lastTime = getCPUCount();
+	calibrate();
+}
+
+void PerfManager::calibrate()
+{
+}
+
+PerfManager::~PerfManager(void)
+{
+}
+
+PerfManager* PerfManager::instance()
+{
+	if(!_instance)		//Double-check locking (first check)
+	{	_instance = new PerfManager();
+	}
+	return _instance;
+}
+
+void PerfManager::enterFunction(const char* const fileName, 
+								const char* const functionName, 
+								const int lineNumber)
+{
+	//Mark the time when we end processing the previous function
+	__int64 endTime = getCPUCount();
+	//assuming we haven't corrupted the stack and reduced it to zero elements
+	if(_perfStack.size())
+	{	PERF_STACK_T::reverse_iterator lastMarker = _perfStack.rbegin();
+		//Update the total time spent processing the previous function
+		__int64 runTime = (endTime - _lastTime) - _callTime;
+		(**lastMarker)._cycles += runTime;
+		_totalTime += runTime;
+	}
+
+	//If we fail to insert the performance marker into our log, it means it is
+	//a duplicate.	We can ignore this "error" as using the existing copy is
+	//the correct behavior.
+	std::pair<PERF_LOG_T::iterator, bool> result = 
+		_perfLog.insert(PerfDatum(fileName, functionName, lineNumber));
+	//Update the call count on the new function:
+	PerfDatum* marker = &*(result.first);
+	marker->_calls++;
+	//Add performance marker to the stack as well as the log:
+	_perfStack.push_back(marker); 
+	//Now that we are clear of any complex operations, we can set the call
+	//time of the new marker more accurately:
+	_lastTime = getCPUCount();
+}
+
+void PerfManager::exitFunction()
+{
+	//Mark the time when we exited the function
+	__int64 endTime = getCPUCount();
+	//Update the function in our log with its new runtime
+	PERF_STACK_T::reverse_iterator lastMarker = _perfStack.rbegin();
+	__int64 runTime = endTime - _lastTime;
+	(**lastMarker)._cycles += runTime;
+	_totalTime += runTime;
+	_perfStack.pop_back();
+	//Lastly, update the function we've fallen back to with the new current
+	//run time.
+	_lastTime = getCPUCount();
+}
+
+__int64 PerfManager::getCPUCount () const
+{
+	_asm rdtsc
+}
+
+bool PerfSort::operator ()(const PerfDatum& lhs, const PerfDatum&rhs) const
+{
+	if(rhs._lineNumber == lhs._lineNumber)
+	{	return 0 < strcmp(rhs._fileName, lhs._fileName);
+	}
+	else
+	{	return rhs._lineNumber > lhs._lineNumber;
+	}
+}
+
+bool PerfSort2::operator ()(const PerfDatum& lhs, const PerfDatum&rhs) const
+{
+	return lhs._cycles > rhs._cycles;
+}
+
+int PerfManager::getPercision(const double value) const
+{
+	int retVal = 1;
+	if(10.0 <= value)
+	{	retVal = 3;
+	}
+	else if (1.0 <= value)
+	{	retVal = 2;
+	}
+	return retVal;
+}
+
+void PerfManager::log(std::ostream &os)
+{
+	//Create a copy of the log that sorts by cycles used
+	std::set<PerfDatum, PerfSort2> logCopy;
+	for(PERF_LOG_T::iterator i = _perfLog.begin(); i != _perfLog.end(); i++)
+	{
+		logCopy.insert(*i);
+	}
+
+	int cyclesWidth = 1;
+	//I want the formatting to be nice!
+	for(std::set<PerfDatum, PerfSort2>::iterator i = logCopy.begin(); 
+		i != logCopy.end(); 
+		i++)
+	{
+		if(i->_lineNumber) {
+			std::stringstream cyclesString;
+			cyclesString << i->_cycles;
+			std::string tempString;
+			cyclesString >> tempString;
+			cyclesWidth = tempString.size();
+			break;
+		}
+	}
+
+	//Stream the sorted log to the supplied ostream
+	for(std::set<PerfDatum, PerfSort2>::iterator i = logCopy.begin(); 
+		i != logCopy.end(); 
+		++i)
+	{
+		if(i->_lineNumber)
+		{	//Truncate path from file name if the compiler included it.
+			const char* j = i->_fileName + strlen(i->_fileName);
+			while('\\' != *j && '/' != *j && j >= i->_fileName){j--;}
+			if('\\' == *j || '/' == *j){j++;}
+			std::stringstream cyclesString;
+			std::string tempString;
+			cyclesString << i->_cycles;
+			cyclesString >> tempString;
+			os.width(cyclesWidth);
+			os << tempString.c_str() << ", ";
+			__int64 cyclesPerCall = i->_cycles / i->_calls;
+			cyclesString.clear();
+			tempString.clear();
+			cyclesString << cyclesPerCall;
+			cyclesString >> tempString;
+			os.width(cyclesWidth);
+			os << tempString.c_str() << "] cycles (";
+			double percent = double(i->_cycles) / double(_totalTime) * 100;
+			os.precision(getPercision(percent));
+			os.width(4);
+			os << percent << "%) used in [";
+			os.width(8);
+			os << i->_calls << "] calls by " << j << "::" << i->_functionName\
+				<< " at line " << i->_lineNumber << std::endl;
+		}
+	}
+}
+
+PerfMarker::PerfMarker( const char* const fileName, 
+						const char* const functionName,
+						const int lineNumber)
+	:
+#ifdef PERIODIC_PROFILING
+	_onStack(gRecordingProfile)
+#else
+	_onStack(true)
+#endif
+{
+#ifdef PERIODIC_PROFILING
+	if (gRecordingProfile == true) {
+#endif
+		PerfManager::instance()->enterFunction(fileName,functionName,lineNumber);
+#ifdef PERIODIC_PROFILING
+	}
+#endif
+}
+
+PerfMarker::~PerfMarker()
+{
+	endMark();
+}
+
+void PerfMarker::endMark()
+{
+	if(_onStack)
+	{	PerfManager::instance()->exitFunction();
+		_onStack = false;
+	}
+}
+#include "profiler.h"
+#include <sstream>
+
+#ifdef PERIODIC_PROFILING
+bool gRecordingProfile = false;
+#endif
+
+PerfManager* PerfManager::_instance(NULL);
+
+PerfDatum::PerfDatum(	const char* const fileName, 
+						const char* const functionName,
+						const int lineNumber,
+						__int64 cycles,
+						__int64 calls)
+	:
+	_fileName(fileName),
+	_functionName(functionName),
+	_lineNumber(lineNumber),
+	_cycles(cycles),
+	_calls(calls)
+{
+}
+
+PerfManager::PerfManager(void)
+	:
+	_callTime(0),
+	_totalTime(0)
+{
+	//Set up a root function so that the stack is never empty:
+	//(this will be the only entry with _lineNumber equal to 0)
+	_perfLog.insert(PerfDatum(__FILE__, "Root",0));
+	_perfStack.push_back(&*(_perfLog.begin()));
+	_lastTime = getCPUCount();
+	calibrate();
+}
+
+void PerfManager::calibrate()
+{
+}
+
+PerfManager::~PerfManager(void)
+{
+}
+
+PerfManager* PerfManager::instance()
+{
+	if(!_instance)		//Double-check locking (first check)
+	{	_instance = new PerfManager();
+	}
+	return _instance;
+}
+
+void PerfManager::enterFunction(const char* const fileName, 
+								const char* const functionName, 
+								const int lineNumber)
+{
+	//Mark the time when we end processing the previous function
+	__int64 endTime = getCPUCount();
+	//assuming we haven't corrupted the stack and reduced it to zero elements
+	if(_perfStack.size())
+	{	PERF_STACK_T::reverse_iterator lastMarker = _perfStack.rbegin();
+		//Update the total time spent processing the previous function
+		__int64 runTime = (endTime - _lastTime) - _callTime;
+		(**lastMarker)._cycles += runTime;
+		_totalTime += runTime;
+	}
+
+	//If we fail to insert the performance marker into our log, it means it is
+	//a duplicate.	We can ignore this "error" as using the existing copy is
+	//the correct behavior.
+	std::pair<PERF_LOG_T::iterator, bool> result = 
+		_perfLog.insert(PerfDatum(fileName, functionName, lineNumber));
+	//Update the call count on the new function:
+	PerfDatum* marker = &*(result.first);
+	marker->_calls++;
+	//Add performance marker to the stack as well as the log:
+	_perfStack.push_back(marker); 
+	//Now that we are clear of any complex operations, we can set the call
+	//time of the new marker more accurately:
+	_lastTime = getCPUCount();
+}
+
+void PerfManager::exitFunction()
+{
+	//Mark the time when we exited the function
+	__int64 endTime = getCPUCount();
+	//Update the function in our log with its new runtime
+	PERF_STACK_T::reverse_iterator lastMarker = _perfStack.rbegin();
+	__int64 runTime = endTime - _lastTime;
+	(**lastMarker)._cycles += runTime;
+	_totalTime += runTime;
+	_perfStack.pop_back();
+	//Lastly, update the function we've fallen back to with the new current
+	//run time.
+	_lastTime = getCPUCount();
+}
+
+__int64 PerfManager::getCPUCount () const
+{
+	_asm rdtsc
+}
+
+bool PerfSort::operator ()(const PerfDatum& lhs, const PerfDatum&rhs) const
+{
+	if(rhs._lineNumber == lhs._lineNumber)
+	{	return 0 < strcmp(rhs._fileName, lhs._fileName);
+	}
+	else
+	{	return rhs._lineNumber > lhs._lineNumber;
+	}
+}
+
+bool PerfSort2::operator ()(const PerfDatum& lhs, const PerfDatum&rhs) const
+{
+	return lhs._cycles > rhs._cycles;
+}
+
+int PerfManager::getPercision(const double value) const
+{
+	int retVal = 1;
+	if(10.0 <= value)
+	{	retVal = 3;
+	}
+	else if (1.0 <= value)
+	{	retVal = 2;
+	}
+	return retVal;
+}
+
+void PerfManager::log(std::ostream &os)
+{
+	//Create a copy of the log that sorts by cycles used
+	std::set<PerfDatum, PerfSort2> logCopy;
+	for(PERF_LOG_T::iterator i = _perfLog.begin(); i != _perfLog.end(); i++)
+	{
+		logCopy.insert(*i);
+	}
+
+	int cyclesWidth = 1;
+	//I want the formatting to be nice!
+	for(std::set<PerfDatum, PerfSort2>::iterator i = logCopy.begin(); 
+		i != logCopy.end(); 
+		i++)
+	{
+		if(i->_lineNumber) {
+			std::stringstream cyclesString;
+			cyclesString << i->_cycles;
+			std::string tempString;
+			cyclesString >> tempString;
+			cyclesWidth = tempString.size();
+			break;
+		}
+	}
+
+	//Stream the sorted log to the supplied ostream
+	for(std::set<PerfDatum, PerfSort2>::iterator i = logCopy.begin(); 
+		i != logCopy.end(); 
+		++i)
+	{
+		if(i->_lineNumber)
+		{	//Truncate path from file name if the compiler included it.
+			const char* j = i->_fileName + strlen(i->_fileName);
+			while('\\' != *j && '/' != *j && j >= i->_fileName){j--;}
+			if('\\' == *j || '/' == *j){j++;}
+			std::stringstream cyclesString;
+			std::string tempString;
+			cyclesString << i->_cycles;
+			cyclesString >> tempString;
+			os.width(cyclesWidth);
+			os << tempString.c_str() << ", ";
+			__int64 cyclesPerCall = i->_cycles / i->_calls;
+			cyclesString.clear();
+			tempString.clear();
+			cyclesString << cyclesPerCall;
+			cyclesString >> tempString;
+			os.width(cyclesWidth);
+			os << tempString.c_str() << "] cycles (";
+			double percent = double(i->_cycles) / double(_totalTime) * 100;
+			os.precision(getPercision(percent));
+			os.width(4);
+			os << percent << "%) used in [";
+			os.width(8);
+			os << i->_calls << "] calls by " << j << "::" << i->_functionName\
+				<< " at line " << i->_lineNumber << std::endl;
+		}
+	}
+}
+
+PerfMarker::PerfMarker( const char* const fileName, 
+						const char* const functionName,
+						const int lineNumber)
+	:
+#ifdef PERIODIC_PROFILING
+	_onStack(gRecordingProfile)
+#else
+	_onStack(true)
+#endif
+{
+#ifdef PERIODIC_PROFILING
+	if (gRecordingProfile == true) {
+#endif
+		PerfManager::instance()->enterFunction(fileName,functionName,lineNumber);
+#ifdef PERIODIC_PROFILING
+	}
+#endif
+}
+
+PerfMarker::~PerfMarker()
+{
+	endMark();
+}
+
+void PerfMarker::endMark()
+{
+	if(_onStack)
+	{	PerfManager::instance()->exitFunction();
+		_onStack = false;
+	}
+}
+
+#endif