/*! * \file PerfTimer.h * \date 2018/01/16 * * \author Lin, Chi * Contact: lin.chi@hzleaper.com * * \note */ #ifndef __PerfTimer_h_ #define __PerfTimer_h_ #include "CVUtils.h" #include "StdUtils.h" #include class PerfTimerSimple { public: PerfTimerSimple() { restart(); } void restart() { mTick = cv::getTickCount(); } int64 elapsed() { return cv::getTickCount() - mTick; } double elapsedMS() { return tickToMS(elapsed()); } static double tickToMS(int64 tick) { static double freq = cv::getTickFrequency() / 1000.; return (double)tick / freq; } private: int64 mTick; }; class PerfTimer { struct PerfInfo { double totalTime; double totalDivisor; std::list times; std::list divisors; string divisorName; PerfInfo(const char* dn = "pixel") : divisorName(dn), totalTime(0.), totalDivisor(0.) {} void add(double t, double d) { totalTime += t; totalDivisor += d; times.push_back(t); divisors.push_back(d); } }; typedef std::map StringPerfInfoMap; typedef std::multimap StringInt64Map; typedef std::multimap::iterator StringInt64MapIter; public: static PerfTimer* get() { static PerfTimer perTimer; return &perTimer; } static PerfTimer* getLogTimer() { static PerfTimer perTimer; return &perTimer; } PerfTimer() { mTickFreq = cv::getTickFrequency(); } ~PerfTimer() { if (!mPerfInfoMap.empty()) print_all("perf.csv"); } inline void setScope(const std::string& name) { mCurScopeName = name; } inline void clearScope() { mCurScopeName.clear(); } inline string substitudeName(const std::string& name) { if (!mCurScopeName.empty()) return string("[") + mCurScopeName + "]" + name; else return string(name); } int64 start(const std::string& name) { int64 tick = cv::getTickCount(); string fullname = substitudeName(name); CyclopsLockGuard mLockGuard(&mLock); mListenMap.insert(std::make_pair(fullname, tick)); return tick; } void end(const std::string& name, double divisor, const char* divisorName = "pixel", bool perfLog = false, int64 tick = 0) { string fullname = substitudeName(name); CyclopsLockGuard mLockGuard(&mLock); StringInt64MapIter it = mListenMap.end(); auto rng = mListenMap.equal_range(fullname); for (auto it0 = rng.first; it0 != rng.second; ++it0) { if (tick == 0 || it0->second == tick) { it = it0; break; } } if (it != mListenMap.end()) { auto it2 = mPerfInfoMap.find(fullname); double t = (getTickCount() - it->second) / mTickFreq; if (it2 == mPerfInfoMap.end()) { mPerfInfoMap[fullname] = PerfInfo(divisorName); } mPerfInfoMap[fullname].add(t, divisor); mListenMap.erase(it); if (perfLog) { std::cout << "[PerfLog]" << fullname << ": " << t * 1000 << "ms" << std::endl; } } } void end(const std::string& name, bool perfLog = true, int64 tick = 0) { end(name, 1, "execution", perfLog, tick); } void print_all(const std::string& filename) { using namespace std; CyclopsLockGuard mLockGuard(&mLock); cout << "===============================================================================" << endl; cout << "====PERFORMANCE ANALYSIS=======================================================" << endl; cout << "====for detailed performance log, check the perf.csv under execution folder.===" << endl; ofstream outFile; outFile.open(filename, std::ofstream::out); outFile << "name,div_name,time,div" << endl; for (auto it = mPerfInfoMap.begin(); it != mPerfInfoMap.end(); it++) { double perT; string div_name; static const int cTrunk = 10000; if (it->second.totalDivisor > cTrunk) { perT = it->second.totalTime / (it->second.totalDivisor / cTrunk); #if (defined(_MSC_VER) && _MSC_VER <= 1600) div_name = std::to_string((_Longlong)cTrunk) + " " + it->second.divisorName; #else div_name = std::to_string(cTrunk) + " " + it->second.divisorName; #endif } else { perT = it->second.totalTime / it->second.totalDivisor; div_name = it->second.divisorName; } cout << it->first << ": " << perT * 1000 << "ms per " << div_name << endl; for (auto it2 = it->second.times.begin(), it3 = it->second.divisors.begin(); it2 != it->second.times.end() && it3 != it->second.divisors.end(); ++it2, ++it3) { outFile << it->first << "," << it->second.divisorName << "," << *it2 << "," << *it3 << endl; } } outFile.close(); cout << "===============================================================================" << endl; mPerfInfoMap.clear(); mListenMap.clear(); } private: StringPerfInfoMap mPerfInfoMap; StringInt64Map mListenMap; double mTickFreq; string mCurScopeName; CyclopsLock mLock; }; #ifdef _PERF_LOG #define START_PERF_LOG(name) PerfTimer::getLogTimer()->start(name); #define END_PERF_LOG(name) PerfTimer::getLogTimer()->end(name); #define START_PERF_LOG_THREAD(name, tick) tick = PerfTimer::getLogTimer()->start(name); #define END_PERF_LOG_THREAD(name, tick) PerfTimer::getLogTimer()->end(name, true, tick); #define START_PERF_SCOPE(name) PerfTimer::getLogTimer()->setScope(name); #define END_PERF_SCOPE() PerfTimer::getLogTimer()->clearScope(); #else #define START_PERF_LOG(name) #define END_PERF_LOG(name) #define START_PERF_LOG_THREAD(name, tick) #define END_PERF_LOG_THREAD(name, tick) #define START_PERF_SCOPE(name) #define END_PERF_SCOPE() #endif // _DEBUG #endif