grof可以获取C程序运行期间的统计数据,如每个函数的耗时,调用次数及各个函数的调用关系,(gprof统计的是CPU占用时间,I/O时间不计算在内)
通常gprof的采样周期是0.01s,统计项越接近这个值误差可能越大。若函数的运行时间低于0.01S,统计值会显示为0。
gprof基本原理
类似于gdb,gprof需要对待分析的程序做一些改动,因此在程序编译的时候需要加上"-pg"选项,如果程序的某个模块在编译的时候没有加上"-pg",则该模块的函数会被排除在统计范围之外。比如想要查看库函数的profiling,则需在链接库函数的时候用“-lc_p"代替”-lc"(gprof是各个类UNIX的标准工具,系统自带的链接库通常有两个版本,它们的区别在于编译的时候是否加上了"-pg"。用-lc_p等于告诉编译器选择加上了"-pg"的那个版本)。
加上"-pg"选项后,程序的入口会于main()之前调用monstartup(),主要是申请内存存储接下来获取的统计信息。
在每个函数中会调用_mcount(),主要是在函数的堆栈中查询父函数和子函数的地址并保存下来。最后会在程序退出前调用_mcleanup(),将统计结果保存到gmon.out中,并完成清除工作。
gprof统计各个函数的运行时间是采用的抽样的方法,周期性的查看Programcounter指向哪一个函数的地址段,并把结果以直方图的形式保存下来。
使用方式
编译时加
-pg
选项,程序正常退出时,生成gmon.out
,通过gprof
可以查看gmon.out
中的统计结果。
gprof -b exe_file
生成分析日志,-b
减少冗余的说明信息
#define MAX 10000000void f() { long long sum = 0; for (long long i=0;i<MAX;i++) sum += i; }void g() { long long sum = 0; for (long long i=0;i<MAX;i++) sum += i; f(); }int main() { long long sum = 0; for (long long i=0;i<MAX;i++) sum += i; f(); g(); }// 编译:g++ -p -o demo demo.cpp// 运行:./demo// 统计:gprof -b demo
数据分析
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 36.12 0.05 0.05 2 25.28 25.28 f() 36.12 0.10 0.05 main 28.89 0.14 0.04 1 40.45 65.73 g()///////////////////////////////////////////////////////////////// %time : 各个函数占用的时间比例,加和应该为 100% cumulative seconds : 累计时间,当前行函数耗时为当前行累计时间减去上一行self seconds : 当前函数耗时不包含子函数 calls : 调用次数self ms/call : 调用一次平均时间(不包含子函数) total ms/call : 调用一次平均耗时(包括子函数) name : 函数名//////////////////////////////////////////////////////////////// Call graph///////////////////////////////////////////////////////////////// 1, 每个函数对应1个 index, 每个函数对应一个 entry2, 不同 entry 之间虚线分割3,每个 entry 中以 index 开始的行成为 primary line4,primary 上面的为 caller line, 下面的为 subroutine line////////////////////////////////////////////////////////////////granularity: each sample hit covers 2 byte(s) for 7.06% of 0.14 seconds index % time self children called name <spontaneous> [1] 100.0 0.05 0.09 main [1] 0.04 0.03 1/1 g() [2] 0.03 0.00 1/2 f() [3] ----------------------------------------------- 0.04 0.03 1/1 main [1] [2] 46.4 0.04 0.03 1 g() [2]///////////////////////////////////////////////////////////////// 1, primary line2, index - 23, time 耗时占比为 46.44, self 当前函数耗时 0.04 不包含子函数5, children 子函数耗时 0.036, called 调用次数//////////////////////////////////////////////////////////////// 0.03 0.00 1/2 f() [3]///////////////////////////////////////////////////////////////// 1, subroutine line2, self 当前函数耗时 0.03 不包含子函数3, children 子函数耗时 0.004, called 1/2 f()共被调用两次,g调用1次////////////////////////////////////////////////////////////////----------------------------------------------- 0.03 0.00 1/2 g() [2] 0.03 0.00 1/2 main [1] [3] 35.7 0.05 0.00 2 f() [3] ----------------------------------------------- Index by function name [3] f() [2] g() [1] main
作者:呆呆的张先生
链接:https://www.jianshu.com/p/9257a5ae3672
共同学习,写下你的评论
评论加载中...
作者其他优质文章