gprof使用介绍 (gcc -pg)

linux服务端编程，性能总是不可避免要思考的问题。

而单机（严格的说是单核）单线程程序（严格的说是逻辑）又是所有复杂应用的基础。所以，这块的性能是整个应用的基础。

当遇到应用相应很慢的时候我们往往会疑问：这么强劲的CPU到底在干什么，反应这么慢。

满足你！linux下常用的性能工具就是跟gcc一起的gprof。来个例子程序：

#include <stdio.h>
#include <stdlib.h>

void f1() {
int i;
int *p;
for (i = 0; i < 10; i++) {
p = malloc(sizeof(int));
*p = 10;
free§;
}
}

void f2() {
int i;
int *p;
for (i = 0; i < 20; i++) {
p = malloc(sizeof(int));
*p = 10;
free§;
}
}

void f3() {
int i;
int *p;
for (i = 0; i < 30; i++) {
p = malloc(sizeof(int));
*p = 10;
free§;
}
}

int main() {
int i;

for (i = 0; i < 1000000; i++) {
f1();
f2();
f3();
}

return 0;
}
哈哈，好烂的程序啊。我们现在要通过gprof找出这个程序运行时cpu都用来干什么了。

要启用gprof很简单，gcc编译的时候带上-pg参数即可：

1
gcc -g -pg test.c -o test
下面运行./test。运行完我们可以看到目录下多了个gmon.out的文件。这就是gprof的日志，里面记录了程序运行cpu的使用信息。打开看看？杯具，二进制文件，我们人类看不懂。。。我们要运行下面的命令生成报表：

1
gprof ./test gmon.out >report.txt
打开report.txt，我们可以看到两张表。

第一张：

Flat profile:

Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ns/call ns/call name
56.25 0.32 0.32 1000000 315.00 315.00 f3
33.04 0.50 0.18 1000000 185.00 185.00 f2
10.71 0.56 0.06 1000000 60.00 60.00 f1
这就是每个函数占用cpu的时间以及百分比了。我们可以很明显的看到f1()、f2()和f3()所用的时间关系。很准确。

第二张表式函数调用表，描述了函数调用的相互关系：

granularity: each sample hit covers 4 byte(s) for 1.79% of 0.56 seconds

index % time self children called name

[1] 100.0 0.00 0.56 main [1]
0.32 0.00 1000000/1000000 f3 [2]
0.18 0.00 1000000/1000000 f2 [3]
0.06 0.00 1000000/1000000 f1 [4]

            0.32    0.00 1000000/1000000     main [1]

[2] 56.2 0.32 0.00 1000000 f3 [2]

            0.18    0.00 1000000/1000000     main [1]

[3] 33.0 0.18 0.00 1000000 f2 [3]

            0.06    0.00 1000000/1000000     main [1]

[4] 10.7 0.06 0.00 1000000 f1 [4]

仔细看吧。

下面介绍个更给力的工具来生成报表（其实是图）——gprof2dot：http://code.google.com/p/jrfonseca/wiki/Gprof2Dot。

接着上面的report.txt，执行下面命令：

gprof2dot report.txt > test.dot

dot -Tpng -o test.png
第一句的意思是将报表转化为dot文件（graphviz http://www.graphviz.org/图像文件格式）。第二句的意思是将这个文件再转为png格式。好吧现在用图像软件打开吧：

不用解释了吧。调用次数/本身所花cpu时间/调用的函数所花时间一目了然！