C++函数调用耗时采集

本文作者原创，首发在本博客；CSDN 上的同名文章已标注为转载并回链到本页：https://blog.csdn.net/qq_30220519/article/details/142656082

目标

快速检测一个函数耗时

测试

#define PROFILER
#include "profiler/profiler.h"

void test() {
	MLX_PROFILE_FUNCTION();
	_sleep(1000);
}

int main(int argc, char* argv[]) {
	mlx::Profiler::get();
	return 0;
}

效果

{“profileData”:[{},
{
    “type” : “function”,
    “name” : “void test(void)”,
    “thread id” : 30040,
    “average duration” : “1010.000000000ms”
}]}

profiler.h

#ifndef __MLX_PROFILER__
#define __MLX_PROFILER__

#include "singleton.h"
#include "mlx_profile.h"
#include <chrono>
#include <string>
#include <thread>
#include <mutex>
#include <fstream>
#include <unordered_map>
#include <sstream>
#include <iomanip>

namespace mlx
{
	using FloatingPointMilliseconds = std::chrono::duration<double, std::milli>;

	struct ProfileResult
	{
		std::string name;
		FloatingPointMilliseconds elapsed_time;
		std::thread::id thread_id;
	};

	class Profiler : public Singleton<Profiler>
	{
		friend class Singleton<Profiler>;

		public:
			Profiler(const Profiler&) = delete;
			Profiler(Profiler&&) = delete;

			void appendProfileData(ProfileResult&& result);

		private:
			Profiler() { beginRuntimeSession(); }
			~Profiler();

			void beginRuntimeSession();
			void writeProfile(const ProfileResult& result);
			void endRuntimeSession();
			inline void writeHeader()
			{
				_output_stream << "{\"profileData\":[{}";
				_output_stream.flush();
			}

			inline void writeFooter()
			{
				_output_stream << "]}";
				_output_stream.flush();
			}

		private:
			std::unordered_map<std::string, std::pair<std::size_t, ProfileResult>> _profile_data;
			std::ofstream _output_stream;
			std::mutex _mutex;
			bool _runtime_session_began = false;
	};

	class ProfilerTimer
	{
		public:
			ProfilerTimer(const char* name) : _name(name)
			{
				_start_timepoint = std::chrono::steady_clock::now();
			}

			inline void stop()
			{
				auto end_timepoint = std::chrono::steady_clock::now();
				auto high_res_start = FloatingPointMilliseconds{ _start_timepoint.time_since_epoch() };
				auto elapsed_time = std::chrono::time_point_cast<std::chrono::milliseconds>(end_timepoint).time_since_epoch() - std::chrono::time_point_cast<std::chrono::milliseconds>(_start_timepoint).time_since_epoch();

				Profiler::get().appendProfileData({ _name, elapsed_time, std::this_thread::get_id() });

				_stopped = true;
			}

			~ProfilerTimer()
			{
				if(!_stopped)
					stop();
			}

		private:
			std::chrono::time_point<std::chrono::steady_clock> _start_timepoint;
			const char* _name;
			bool _stopped = false;
	};

	namespace ProfilerUtils 
	{
		template <std::size_t N>
		struct ChangeResult
		{
			char data[N];
		};

		template <std::size_t N, std::size_t K>
		constexpr auto cleanupOutputString(const char(&expr)[N], const char(&remove)[K])
		{
			ChangeResult<N> result = {};

			std::size_t src_index = 0;
			std::size_t dst_index = 0;
			while(src_index < N)
			{
				std::size_t match_index = 0;
				while(match_index < K - 1 && src_index + match_index < N - 1 && expr[src_index + match_index] == remove[match_index])
					match_index++;
				if(match_index == K - 1)
					src_index += match_index;
				result.data[dst_index++] = expr[src_index] == '"' ? '\'' : expr[src_index];
				src_index++;
			}
			return result;
		}
	}
}

#ifdef PROFILER
	#define MLX_PROFILE_SCOPE_LINE2(name, line) constexpr auto fixedName##line = ::mlx::ProfilerUtils::cleanupOutputString(name, "__cdecl ");\
												::mlx::ProfilerTimer timer##line(fixedName##line.data)
	#define MLX_PROFILE_SCOPE_LINE(name, line) MLX_PROFILE_SCOPE_LINE2(name, line)
	#define MLX_PROFILE_SCOPE(name) MLX_PROFILE_SCOPE_LINE(name, __LINE__)
	#define MLX_PROFILE_FUNCTION() MLX_PROFILE_SCOPE(MLX_FUNC_SIG)
#else
	#define MLX_PROFILE_SCOPE(name)
	#define MLX_PROFILE_FUNCTION()
#endif

#endif

profiler.cpp

#include "profiler.h"
#include "errors.cpp"
#include <iostream>

namespace mlx
{
	void Profiler::beginRuntimeSession()
	{
		std::lock_guard lock(_mutex);
		if(_runtime_session_began)
			return;
		_output_stream.open("./runtime_profile.mlx.json", std::ofstream::out | std::ofstream::trunc);

		if(_output_stream.is_open())
			writeHeader();
		else
			core::error::report(e_kind::error, "Profiler : cannot open runtime profile file");
		_runtime_session_began = true;
	}

	void Profiler::appendProfileData(ProfileResult&& result)
	{
		std::lock_guard lock(_mutex);
		auto it = _profile_data.find(result.name);
		if(it != _profile_data.end())
		{
			result.elapsed_time = (result.elapsed_time + it->second.second.elapsed_time) / it->second.first;
			_profile_data[result.name].first++;
			_profile_data[result.name].second = result;
		}
		else
			_profile_data[result.name] = std::make_pair(1, result);
	}

	void Profiler::writeProfile(const ProfileResult& result)
	{
		std::stringstream json;
		json << std::setprecision(9) << std::fixed;
		json << ",\n{\n";
		json << "\t\"type\" : \"function\"," << '\n';
		json << "\t\"name\" : \"" << result.name << "\"," << '\n';
		json << "\t\"thread id\" : " << result.thread_id << "," << '\n';
		json << "\t\"average duration\" : \"" << result.elapsed_time.count() << "ms\"\n";
		json << "}";
		_output_stream << json.str();
	}

	void Profiler::endRuntimeSession()
	{
		std::lock_guard lock(_mutex);
		if(!_runtime_session_began)
			return;
		for(auto& [_, pair] : _profile_data)
			writeProfile(pair.second);
		writeFooter();
		_output_stream.close();
		_profile_data.clear();
		_runtime_session_began = false;
	}

	Profiler::~Profiler()
	{
		if(!_runtime_session_began)
			return;
		endRuntimeSession();
	}
}

---

创作不易，小小的支持一下吧！

赏

谢谢你请我吃糖果

支付宝