newValue/3part/Cyclops/include/PerfTimer.h

/*!
 * \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 <map>

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<double> times;
		std::list<double> 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<string, PerfInfo> StringPerfInfoMap;
	typedef std::multimap<string, int64> StringInt64Map;
	typedef std::multimap<string, int64>::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