前段时间做产品的性能测试,用了一段时间gprof,感觉很强大。
1. gprof介绍
gprof是GNU profiler工具。可以显示程序运行的“flat profile”,包括每个函数的调用次数,每个函数消耗的处理器时间。也可以显示“调用图”,包括函数的调用关系,每个函数调用花费了多少时间。还可以显示“注释的源代码”,是程序源代码的一个复本,标记有程序中每行代码的执行次数。
常用与Linux,默认是自带的。如果想在windows下使用,需要安装类似MinGw,安装完后,即可使用。
2. 使用方法
基本用法:
1.使用-pg选项编译和链接你的应用程序。
2.运行你的应用程序,使之运行完成后生成供gprof分析的数据文件(默认是gmon.out)。
3.使用gprof程序分析你的应用程序生成的数据。
4. (可选, 见章节4)可用python生成png图来直观看。
举例(在windows下测试)
gcc -pg -o test test.c //程序文件名称 test.c 编译时使用 -pg
现在我们可以再次运行生成的结果文件test ,并使用我们前面使用的测试数据。这次我们运行的时候,test运行的分析数据会被搜集并保存在'gmon.out'文件中,我们可以通过运行 ‘gprof test gmon.out>result’到一个result文件来查看结果。
a.exe
gprof a.exe gmon.out>result
或
gprof a.exe(直接在命令行下查看)
3. 原理分析
在所有的函数内部加入了三个函数:
.cfi_startproc负责初始化profile环境,分配内存空间
_mcount记录每个函数代码的caller和callee的位置
.cfi_endproc清除profile环境,保存结果数据为gmon.out,供gprof分析结果
在编译和链接程序的时候(使用 -pg 编译和链接选项),gcc 在你应用程序的每个函数中都加入了一个名为mcount(or“_mcount”, or“__mcount”)的函数,也就是说-pg编译的应用程序里的每一个函数都会调用mcount, 而mcount会在内存中保存一张函数调用图,并通过函数调用堆栈的形式查找子函数和父函数的地址。这张调用图也保存了所有与函数相关的调用时间,调用次数等等的所有信息。
程序运行结束后,会在程序退出的路径下生成一个 gmon.out文件。这个文件就是记录并保存下来的监控数据。可以通过命令行方式的gprof或图形化的Kprof来解读这些数据并对程序的性能进行分析。
4. 生成png调用关系图
此操作需要在windows上执行,
1. 需要安装python2.7.3和graphviz。
2. 需要脚本"gprof2dot.py"和xdot.py
步骤:
1. gprof a.exe gmon.out>result ---先生成result文件
2. gprof2dot.py report.txt > report.dot --python转为dot文件
3. dot -Tpng -oreport.png report.dot --生成png文件
5. 命令行选项及结果参数解释
a. 常用的gprof命令选项(命令行显示结果时使用):
选项 |
解释 |
-b |
不再输出统计图表中每个字段的详细描述。 |
-p |
只输出函数的调用图(Call graph的那部分信息)。 |
-q |
只输出函数的时间消耗列表。 |
-e Name |
不再输出函数Name 及其子函数的调用图(除非它们有未被限制的其它父函数)。可以给定多个 -e 标志。一个 -e 标志只能指定一个函数。 |
-E Name |
不再输出函数Name 及其子函数的调用图,此标志类似于 -e 标志,但它在总时间和百分比时间的计算中排除了由函数Name 及其子函数所用的时间。 |
-f Name |
输出函数Name 及其子函数的调用图。可以指定多个 -f 标志。一个 -f 标志只能指定一个函数。 |
-F Name |
输出函数Name 及其子函数的调用图,它类似于 -f 标志,但它在总时间和百分比时间计算中仅使用所打印的例程的时间。可以指定多个 -F 标志。一个 -F 标志只能指定一个函数。-F 标志覆盖 -E 标志。 |
-z |
显示使用次数为零的例程(按照调用计数和累积时间计算)。 |
b. gprof产生的结果中调用时间信息解释
% cumulative self self total
time seconds seconds calls Ts/call Ts/call name
0.00 0.00 0.00 5140 0.00 0.00 CC()
0.00 0.00 0.00 100 0.00 0.00 AA(int)
0.00 0.00 0.00 20 0.00 0.00 BB(int)
0.00 0.00 0.00 1 0.00 0.00 printA(int)
0.00 0.00 0.00 1 0.00 0.00 printB(int)
选项 |
解释 |
% time |
the percentage of the total running time of theprogram used by this function. 函数使用时间占所有时间的百分比。 |
cumulative seconds |
a running sum of the number of seconds accounted for by this function and those listed above it. 函数和上列函数累计执行的时间。 |
self seconds |
the number of seconds accounted for by this function alone. This is the major sort for this listing. 函数本身所执行的时间。 |
self ms/call |
the average number of milliseconds spent in this function per call, if this function is profiled, else blank. 每一次调用花费在函数的时间microseconds。 |
total ms/call |
the average number of milliseconds spent in this function and its descendents per call, if this function is profiled, else blank. 每一次调用,花费在函数及其衍生函数的平均时间microseconds。 |
name |
the name of the function. This is the minor sort for this listing. The index shows the location of the function in the gprof listing. If the index is in parenthesis it shows where it would appear in the gprof listing if it were to be printed. 函数名。 |
c. 结果中Call graph (explanation follows)
index % time self children called name
-----------------------------------------------
0.00 0.00 190/5140 BB(int) [4]
0.00 0.00 4950/5140 AA(int) [3]
[2] 0.0 0.00 0.00 5140 CC() [2]
-----------------------------------------------
0.00 0.00 100/100 printA(int) [5]
[3] 0.0 0.00 0.00 100 AA(int) [3]
0.00 0.00 4950/5140 CC() [2]
-----------------------------------------------
0.00 0.00 20/20 printB(int) [6]
[4] 0.0 0.00 0.00 20 BB(int) [4]
0.00 0.00 190/5140 CC() [2]
-----------------------------------------------
0.00 0.00 1/1 main [74]
[5] 0.0 0.00 0.00 1 printA(int) [5]
0.00 0.00 100/100 AA(int) [3]
-----------------------------------------------
0.00 0.00 1/1 main [74]
[6] 0.0 0.00 0.00 1 printB(int) [6]
0.00 0.00 20/20 BB(int) [4]
-----------------------------------------------
注:按照调用时间排序,整个函数调用树被分为很多块。每一个用横线包围起来的块是一个函数调用分支。在某个块中,左侧带有索引的是当前关注的函数,其上方一行是调用它的函数,下方是它调用的函数。蓝色表示当前函数。
选项 |
解释 |
index |
A unique number given to each element of the table. Index numbers are sorted numerically. The index number is printed next to every function name so it is easier to look up where the function is in the table.每个函数的index值。 |
% time |
This is the percentage of the `total' time that was spent in this function and its children. Note that due to different viewpoints, functions excluded by options, etc, these numbers will NOT add up to 100%.这个函数和它的子函数消耗的所有时间。 |
self |
This is the total amount of time spent in this function.这个函数自己占用的时间 |
children |
This is the total amount of time propagated into this function by its children.这个函数的子函数所消耗的时间 |
called |
1. 如果是它本身:没有分号--这个函数在这个分支调用了多少次。 2. 如果是父函数:父函数调用这个函数次数/这个函数被调用的总次数。 3. 如果是子函数:这个函数调用此子函数的次数/此子函数被调用的总次数。 |
name |
The name of the current function. The index number is printed after it. If the function is a member of a cycle, the cycle number is printed between the function's name and the index number. 函数名。 |
6. 使用注意
1) 一般gprof只能查看用户函数信息。如果想查看库函数的信息,需要在编译是再加入“-lc_p”编译参数代替“-lc”编译参数,这样程序会链接libc_p.a库,才可以产生库函数的profiling信息。
2)还有一点要注意的就是当程序非正常终止时不会生成gmon.out文件,也因此就没法查看程序运行时的信息。只有当程序从main函数中正常退出,或者通过系统调用exit()函数而退出时,才会生成gmon.out文件。而通过底层调用如_exit()等退出时不会生成gmon.out。例如:
static void sighandler( int sig_no )
{
exit(0);
}
signal( SIGUSR1, sighandler );
当使用kill -USR1 pid 后,程序退出,生成gmon.out文件。
3) 如果没有多少时间被花费在执行用户空间的代码上,因此gprof效果不好。
7. 相关资料
Graphviz 工具:http://www.graphviz.org
http://www.ibm.com/developerworks/cn/linux/l-gnuprof.html
gprof手册:http://sourceware.org/binutils/docs-2.16/gprof/index.html
http://www.jtben.com/document/205310