函数执行时间

使用方法,在函数第一行加入下面

CFunctionTime cf(__FUNCTION__);

或

CFunctionTime cf("XXX函数");

源码

#pragma once

#include <boost/timer.hpp>
#include <boost/date_time.hpp>
#include <boost/date_time/time.hpp>
#include <string>
#include "LogManager.h"

class CFunctionTime
{
public:
	CFunctionTime(std::string strInfo)
	{
		m_strInfo = strInfo;
		std::string strTime = boost::posix_time::to_iso_string(boost::posix_time::second_clock::local_time());
		CLogManager::instance()->SetLogInfoFmt(LOGDEBUG,"[%s]开始时间[%s]!",m_strInfo.c_str(),strTime.c_str());
	};
	~CFunctionTime()
	{
		std::string strTime = boost::posix_time::to_iso_string(boost::posix_time::second_clock::local_time());
		CLogManager::instance()->SetLogInfoFmt(LOGDEBUG,"[%s]结束时间[%s]!",m_strInfo.c_str(),strTime.c_str());
		double dTime = m_FunctionTimer.elapsed();
		if (dTime>0)
		{
			CLogManager::instance()->SetLogInfoFmt(LOGDEBUG,"[%s]使用时间[%f]!",m_strInfo.c_str(),dTime);
		}
	};
private:
	std::string m_strInfo;
	boost::timer m_FunctionTimer;//定时器
};

class CFunctionStepTime
{
public:
	CFunctionStepTime(const std::string& strFunInfo, DWORD debugMinTime = 1000)
		: _debugTime(debugMinTime)
		, m_tpStart(std::chrono::system_clock::now())
		, m_steadyStart(std::chrono::steady_clock::now())
		, m_strFunctionInfo(strFunInfo)
	{
		m_objStepInfos.reserve(10);
		AddStep("函数开始");
	}
	~CFunctionStepTime()
	{
		AddStep("函数结束");
		std::string strFormatTime = FormatTime(m_tpStart);
		std::chrono::system_clock::time_point tpEnd = std::chrono::system_clock::now();
		std::chrono::steady_clock::time_point steadyEnd = std::chrono::steady_clock::now();
		std::chrono::steady_clock::time_point steadyPreStep = m_steadyStart;
		//===================================================================================//
		auto nFunUseTime = std::chrono::duration_cast<std::chrono::milliseconds>(steadyEnd - m_steadyStart).count();

		std::stringstream strOutInfo;
		strOutInfo << std::endl << m_strFunctionInfo << ":" << strFormatTime << "[" << std::fixed << std::setprecision(3) << nFunUseTime / 1000.0 << "]" << std::endl;
		strOutInfo << "{" << std::endl;
		for (auto&& objInfo : m_objStepInfos)
		{
			strOutInfo << "\t"
				<< "[" << std::fixed << std::setw(8) << std::setprecision(3) << (std::chrono::duration_cast<std::chrono::milliseconds>(objInfo.steadyStep - m_steadyStart).count()) / 1000.0 << "]"
				<< "[" << std::fixed << std::setw(8) << std::setprecision(3) << (std::chrono::duration_cast<std::chrono::milliseconds>(objInfo.steadyStep - steadyPreStep).count()) / 1000.0 << "]" << ":" << objInfo.strStepInfo << std::endl;
			steadyPreStep = objInfo.steadyStep;
		}
		strOutInfo << "}" << std::endl;
		if (nFunUseTime > _debugTime)
		{
			switch (m_nTimeOutLevel)
			{
			case SPDLOG_LEVEL_TRACE:
				SPDLOG_TRACE("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_DEBUG:
				SPDLOG_DEBUG("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_INFO:
				SPDLOG_INFO("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_WARN:
				SPDLOG_WARN("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_ERROR:
				SPDLOG_ERROR("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_CRITICAL:
				SPDLOG_CRITICAL("{}", strOutInfo.str());
				break;
			default:
				SPDLOG_DEBUG("{}", strOutInfo.str());
				break;
			}
		}
		else
		{
			switch (m_nLevel)
			{
			case SPDLOG_LEVEL_TRACE:
				SPDLOG_TRACE("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_DEBUG:
				SPDLOG_DEBUG("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_INFO:
				SPDLOG_INFO("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_WARN:
				SPDLOG_WARN("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_ERROR:
				SPDLOG_ERROR("{}", strOutInfo.str());
				break;
			case SPDLOG_LEVEL_CRITICAL:
				SPDLOG_CRITICAL("{}", strOutInfo.str());
				break;
			default:
				SPDLOG_TRACE("{}", strOutInfo.str());
				break;
			}
		}
	}
public:
	void SetLogLevel(const int nTimeOutLevel, const int nLevel)
	{
		m_nTimeOutLevel = nTimeOutLevel;
		m_nLevel = nLevel;
	}
	void AddStep(const std::string& strStepInfo)
	{
		m_objStepInfos.emplace_back(strStepInfo);
	}
	std::string FormatTime(const std::chrono::system_clock::time_point& tp)
	{
		std::time_t timeStart = std::chrono::system_clock::to_time_t(tp);
		std::tm tmStart;
		localtime_s(&tmStart, &timeStart);//localtime_r
		char mbstr[100];
		size_t size = std::strftime(mbstr, sizeof(mbstr), "%Y-%m-%d %H:%M:%S", &tmStart);
		std::string strFormatTime;
		if (size) {
			strFormatTime = mbstr;
		}
		return strFormatTime;
	}
private:
	struct StepInfo
	{
		StepInfo(const std::string& str) : steadyStep(std::chrono::steady_clock::now()), strStepInfo(str) {}
		std::chrono::steady_clock::time_point steadyStep;
		std::string strStepInfo;
	};
private:
	std::string m_strFunctionInfo;
	std::chrono::system_clock::time_point m_tpStart;
	std::chrono::steady_clock::time_point m_steadyStart;
	std::vector<StepInfo> m_objStepInfos;
	DWORD _debugTime = 1000;
	int m_nTimeOutLevel = SPDLOG_LEVEL_DEBUG;
	int m_nLevel = SPDLOG_LEVEL_TRACE;
};

CFunctionStepTime ft("xxxxxxxx");
ft.AddStep("AAAA调用");
....
ft.AddStep("AAAA结束");
....
ft.AddStep("BBBB调用");
....
ft.AddStep("BBBB结束");
....


输出

XXXX:2024-04-08 09:41:36[1.217]
{
        [   0.000][   0.000]:函数开始
        [   0.000][   0.000]:AAAA开始
        [   0.000][   0.000]:AAAA结束
        [   0.000][   0.000]:BBBB开始
        [   0.099][   0.099]:BBBB结束
        [   1.217][   0.006]:函数结束
}