#include "AP_PerfMon.h" extern const AP_HAL::HAL& hal; // static class variable definitions uint8_t AP_PerfMon::nextFuncNum; char AP_PerfMon::functionNames[PERFMON_MAX_FUNCTIONS][PERFMON_FUNCTION_NAME_LENGTH]; uint32_t AP_PerfMon::time[PERFMON_MAX_FUNCTIONS]; uint32_t AP_PerfMon::maxTime[PERFMON_MAX_FUNCTIONS]; uint32_t AP_PerfMon::numCalls[PERFMON_MAX_FUNCTIONS]; uint32_t AP_PerfMon::allStartTime; uint32_t AP_PerfMon::allEndTime; AP_PerfMon* AP_PerfMon::lastCreated = NULL; bool AP_PerfMon::_enabled = true; // constructor AP_PerfMon::AP_PerfMon(uint8_t funcNum) : _funcNum(funcNum), _time_this_iteration(0) { // exit immediately if we are disabled if( !_enabled ) { return; } // check global start time if( allStartTime == 0 ) { allStartTime = hal.scheduler->micros(); } // stop recording time from parent _parent = lastCreated; // add pointer to parent if( _parent != NULL ) { _parent->stop(); } // record myself as the last created instance lastCreated = this; numCalls[_funcNum]++; // record that this function has been called start(); // start recording time spent in this function } // destructor AP_PerfMon::~AP_PerfMon() { // exit immediately if we are disabled if( !_enabled ) { return; } stop(); // stop recording time spent in this function lastCreated = _parent; // make my parent the last created instance // calculate max time spent in this function if( _time_this_iteration > maxTime[_funcNum] ) { maxTime[_funcNum] = _time_this_iteration; } // restart recording time for parent if( _parent != NULL ) _parent->start(); } // record function name in static list uint8_t AP_PerfMon::recordFunctionName(const char funcName[]) { uint8_t nextNum = nextFuncNum++; uint8_t i; // clear existing function name (if any) functionNames[nextNum][0] = 0; // store function name for( i=0; imicros(); // start recording time spent in this function } // stop recording time void AP_PerfMon::stop() { uint32_t temp_time = hal.scheduler->micros()-_startTime; _time_this_iteration += temp_time; time[_funcNum] += temp_time; } // ClearAll - clears all data from static members void AP_PerfMon::ClearAll() { uint8_t i; AP_PerfMon *p = lastCreated; for(i=0; imicros(); allEndTime = 0; // reset start times of any active counters while( p != NULL ) { p->_startTime = allStartTime; p = p->_parent; } } // DisplayResults - displays table of timing results void AP_PerfMon::DisplayResults() { uint8_t i,j,changed; float hz; float pct; uint32_t totalTime; uint32_t avgTime; uint32_t sumOfTime = 0; uint32_t unExplainedTime; uint8_t order[PERFMON_MAX_FUNCTIONS]; // record end time if( allEndTime == 0 ) { allEndTime = hal.scheduler->micros(); } // turn off any time recording if( lastCreated != NULL ) { lastCreated->stop(); } _enabled = false; // reorder results for(i=0; iset_blocking_writes(true); // print table of results hal.console->printf("\nPerfMon elapsed:%lu(ms)\n",(unsigned long)totalTime/1000); hal.console->printf("Fn:\t\tcpu\ttot(ms)\tavg(ms)\tmax(ms)\t#calls\tHz\n"); for( i=0; i 0 ) { avgTime = time[j] / numCalls[j]; }else{ avgTime = 0; } hz = numCalls[j]/(totalTime/1000000); pct = ((float)time[j] / (float)totalTime) * 100.0f; hal.console->printf("%-10s\t%4.2f\t%lu\t%4.3f\t%4.3f\t%lu\t%4.1f\n", functionNames[j], pct, (unsigned long)time[j]/1000, (float)avgTime/1000.0f, (float)maxTime[j]/1000.0f, numCalls[j], hz); } // display unexplained time if( sumOfTime >= totalTime ) { unExplainedTime = 0; } else { unExplainedTime = totalTime - sumOfTime; } pct = ((float)unExplainedTime / (float)totalTime) * 100.0f; hal.console->printf("unexpl:\t\t%4.2f\t%lu\n",pct,(unsigned long)unExplainedTime/1000); // restore to blocking writes if necessary hal.console->set_blocking_writes(false); // turn back on any time recording if( lastCreated != NULL ) { lastCreated->start(); } _enabled = true; } // DisplayAndClear - will display results after this many milliseconds. should be called regularly void AP_PerfMon::DisplayAndClear(uint32_t display_after_seconds) { if( (hal.scheduler->micros() - allStartTime) > (uint32_t)(display_after_seconds * 1000000) ) { DisplayResults(); ClearAll(); } }