#ifdef PROFILER_ENABLED #include "builddefines.h" #include #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 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 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::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::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 #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 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 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::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::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