C++性能分析小工具

自己做的性能分析"工具", 其实是一小段代码, 嵌入C++工程里用, 能统计出各函数的独占运行时间.

使用方法

1 包含头文件

#define ENABLE_PROFILE // 开关#include "Profiler.h" 

2 在要分析的函数中添加一个宏(比较烦, 但也只能这样)

void func(){ FUNCTION_PROFILE ……}

3 在退出程序前打印结果

PrintProfileResult();

原理

•  每个函数里放一个静态的"分析结果"(FunctionProfile)对象, 用来记录这个函数的分析结果.
•  每个函数里放一个非静态的"栈帧"(ProfilerStackFrame)对象, 并和相应的"分析结果"相关联,  用来统计一次调用的时间.
•  在"栈帧"的构造函数里记录调用的起始时间, 在析构函数里计算出独占时间, 累加到结果里.
•  程序结束前, 把全部"分析结果"按耗时排序, 输出.

线程安全性

支持多线程, 但会把所有线程的运行时间累加到一起, 分不清是那个线程耗时多, 那个耗时少. 

运行结果:

profile result:
func_b():       0.726132        10
func_a():       0.723048        12
test():         0.000138        1
ThreadFunc():   0.000000        1

完整代码 (LINUX版的计时精度可能不够, 请自行换成高精度计时器)

 

Profiler.h

 

#pragma oncetypedef unsigned long long uint64;// 存放函数的性能分析结果, 每个FunctionProfile对象对应一个函数struct FunctionProfile{const char * func; // 函数名uint64 callCount; // 调用次数uint64 timeExclusive; // 独占运行时间FunctionProfile(const char * _func);void Print(); // 打印这个函数的分析结果};struct ProfilerStackFrame{FunctionProfile * profile; // 这一帧对应的分析数据ProfilerStackFrame * caller; // 这一帧的调用者(上一帧)uint64 timeBegin0; // 包含Profiler本身耗时uint64 timeBegin1; // 不包含Profiler本身耗时uint64 timeSub; // 这一帧调用的所有子函数的耗时总和ProfilerStackFrame(FunctionProfile * _profile);~ProfilerStackFrame();};// 输出结果void PrintProfileResult();#ifdef ENABLE_PROFILE// 定义一个宏便于使用, 注意funcProfile是静态变量, funcFrame是局部变量#define FUNCTION_PROFILE /static FunctionProfile __funcProfile( __FUNCTION__);/ProfilerStackFrame __funcFrame(&__funcProfile);#else// 关闭性能分析时的替代宏, 什么也不做#define FUNCTION_PROFILE ((void)0);#endif

 

Profiler.cpp

// 省略了部分错误检查, 如有需要请自行补完.#ifdef _WIN32#include <Windows.h>#else#include <unistd.h>#include <sys/times.h>#include <pthread.h>#endif#include <list>#include <assert.h>#include <stdio.h>#include "Profiler.h"#ifdef _WIN32class Mutex{CRITICAL_SECTION cs;public:Mutex(){::InitializeCriticalSection(&cs);}~Mutex(){::DeleteCriticalSection(&cs);};void Lock(){::EnterCriticalSection(&cs);}void Unlock(){::LeaveCriticalSection(&cs);}};// 普通函数运行极快, 必须用高分辨率计时器. 我们用系统自带的做一个inline static uint64 GetTicks64(){uint64 ret;return QueryPerformanceCounter((LARGE_INTEGER*)&ret) ? ret : 0;}// 时钟频率, 用来换算成秒inline static uint64 GetTicks64Frequency(){uint64 ret;return QueryPerformanceFrequency((LARGE_INTEGER*)&ret) ? ret : 1000;}#elseclass Mutex{pthread_mutex_t mutex;pthread_mutexattr_t mta;public:Mutex(){pthread_mutexattr_init(&mta);pthread_mutexattr_settype(&mta, PTHREAD_MUTEX_RECURSIVE);pthread_mutex_init(&mutex, &mta);}~Mutex(){pthread_mutex_destroy(&mutex);pthread_mutexattr_destroy(&mta);};void Lock(){pthread_mutex_lock(&mutex);}void Unlock(){pthread_mutex_unlock(&mutex);}};inline static uint64 GetTicks64(){tms tm;return (unsigned long long)times(&tm);}inline static uint64 GetTicks64Frequency(){return sysconf(_SC_CLK_TCK);}#endif// 多线程支持, 做成函数是为了回避全局对象初始化顺序的问题static Mutex & g_profiler_mutex(){static Mutex _profiler_mutex;return _profiler_mutex;}#ifdef _MSC_VER#define __thread __declspec(thread) // __thread是GCC关键字, VC的要用__declspec(thread)#endif// 用来记录上最后一堆栈帧的变量, 每个线程都有一个, 所以要用TLSstatic __thread ProfilerStackFrame * g_last_stack_frame = 0;static const int MAX_PROFILE_FUNC = 2000; // 不够可扩充. // 最好别用std::vector或std::list, 否则可能会遇到全局对象构造顺序的问题static FunctionProfile* g_func_profile_array[MAX_PROFILE_FUNC]; static unsigned int g_func_profile_count = 0;FunctionProfile::FunctionProfile(const char * _func): func(_func){callCount = 0;timeExclusive = 0;//多线程时有要加锁g_profiler_mutex().Lock();assert(g_func_profile_count < MAX_PROFILE_FUNC); // 确保不数组够用g_func_profile_array[g_func_profile_count++] = this;g_profiler_mutex().Unlock();}void FunctionProfile::Print(){// 函数名是0时就不打印(想想看有什么用)if(func == 0){return;}g_profiler_mutex().Lock();// 转换成秒float te = timeExclusive / (float) GetTicks64Frequency(); printf("%s(): /t%f /t%g/n", func, te, (float)callCount);g_profiler_mutex().Unlock();}ProfilerStackFrame::ProfilerStackFrame(FunctionProfile * _profile) {// 要记录两个开始时间, 已减少误差// 这个构造函数的call/ret和压栈出栈时间, 以及计时器本身损耗(大概)不能直接获得, 只好忽略了timeBegin0 = GetTicks64(); // 必须放在函数的最前面profile = _profile; // 把堆栈帧和函数对应起来caller = g_last_stack_frame; // 记住调用者g_last_stack_frame = this; // 最后一帧变成当前帧timeSub = 0; // 构造完后, 才是这一帧的"真正"开始时间, timeBegin1 = GetTicks64(); // 必须放在函数的最后}ProfilerStackFrame::~ProfilerStackFrame(){// 计算这一帧的实际耗时(非独占), uint64 t = GetTicks64() - timeBegin1; // 必须放在函数的最前面// 这一帧即将消失, 最后一帧将变为上一帧g_last_stack_frame = caller;if(profile){// 时间累加, 多线程时必须加锁g_profiler_mutex().Lock();profile->callCount++; // 调用次数加1profile->timeExclusive+= t - timeSub; // 时间累加, 非独占时间减去子函数的耗时就是独占g_profiler_mutex().Unlock();}if(caller){// 要把当前帧的耗时累加到caller的子函数耗时中.caller->timeSub+= GetTicks64() - timeBegin0; // 必须放在函数的最后}}// 这是排序用的比较函数, 时间长的排前面struct MoreTimeFirst{bool operator()(FunctionProfile * _l, FunctionProfile * _r) const{return _l->timeExclusive > _r->timeExclusive;}};// 排序并打印结果void PrintProfileResult(){g_profiler_mutex().Lock();typedef std::list<FunctionProfile*> FunctionProfileList;FunctionProfileList func_profile_list; // 把结果扔进list里for(unsigned int i = 0; i < g_func_profile_count; i++){func_profile_list.push_back(g_func_profile_array[i]);}// 排序func_profile_list.sort(MoreTimeFirst());printf("profile result:/n");FunctionProfileList::iterator it = func_profile_list.begin();for(; it!= func_profile_list.end(); ++it){FunctionProfile * o = *it;o->Print();}g_profiler_mutex().Unlock();}

 

test.cpp

#include <math.h>#include <stdio.h>#ifdef _WIN32#include <Windows.h>#else#include <pthread.h>#endif#define ENABLE_PROFILE // 性能分析开关#include "Profiler.h"float dummySum = 0;void func_b(int n);void func_a(int n){FUNCTION_PROFILE;if(n){func_b(n-1);for(int i=0; i<1000000; i++){dummySum+= sin((float)i);}}}void func_b(int n){FUNCTION_PROFILE;if(n){func_a(n-1);for(int i=0; i<1000000; i++){dummySum+= cos((float)i);}}}#ifdef _WIN32DWORD WINAPI ThreadFunc(LPVOID){FUNCTION_PROFILE;func_a(10);return 0;}void test(){FUNCTION_PROFILE;DWORD tid;HANDLE hThread = CreateThread(0, 0, &ThreadFunc, 0, 0, &tid);func_a(10);// 等另一个线程结束::WaitForSingleObject(hThread, INFINITE);}#elsevoid * ThreadFunc(void *){FUNCTION_PROFILE;func_a(10);return 0;}void test(){FUNCTION_PROFILE;pthread_t id;pthread_create(&id, 0, &ThreadFunc, 0);func_a(10);// 等另一个线程结束void * status;pthread_join(id, &status);}#endifint main(int argc, char ** argv){test();PrintProfileResult();getchar();return 0;}