使用 gprof 进行简单程序的性能分析

作者：SkyFire

2021 年 12 月 29 日
本文字数：3040 字
阅读完需：约 10 分钟

使用`gprof`进行简单程序的性能分析

简介

gprof产生程序运行时候的函数调用关系，包括调用次数，函数运行时间，调用关系等，可以帮助程序员分析程序的运行流程以及性能瓶颈，以达到编写更高效程序的目的。

使用方法

gprof的使用方法很简单，大致分为以下几个步骤。

使用-pg参数编译可执行程序。
运行可执行程序。
使用gprof生成分析结果。

例子

我们编写一个程序来演示一下如何使用gprof。

程序的源码如下（程序没有特殊含义，只是为了演示gprof的使用）：

// filename : main.cpp#include <bits/stdc++.h>
using namespace std;
void xor_calc(){    int t = 0;    for (int i = 0; i < INT32_MAX; ++i)        t ^= i;}
void time_cost1(){    for (int i = 0; i < 3; ++i)        xor_calc();}
void time_cost2(){    for (int i = 0; i < 5; ++i)        xor_calc();}
int main(){    time_cost1();    time_cost2();    return 0;}

复制代码

使用-pg参数编译程序：

g++ main.cpp -o main -pg

复制代码

得到可执行程序main。

运行main程序。

./main

复制代码

程序运行结束后会产生一个gmon.out文件。

使用gprof生成分析结果。

gprof main -b -a

复制代码

此时我们使用了参数-b和-a，后续会介绍这两个参数。

注意：这里使用的是main，而不是gmon.out。

此时终端输出分析结果。（也可以使用gprof main > filename将输出重定向到文件便于分析）。

输出结果可以分为两个部分，第一个部分如下：

Flat profile:
Each sample counts as 0.01 seconds.  %   cumulative   self              self     total            time   seconds   seconds    calls   s/call   s/call  name    100.50     35.73    35.73        8     4.47     4.47  xor_calc()  0.00     35.73     0.00        1     0.00    13.40  time_cost1()  0.00     35.73     0.00        1     0.00    22.33  time_cost2()  0.00     35.73     0.00        1     0.00    35.73  main

复制代码

上一部分给出了分析结果，下面的部分是对分析结果的解释。

可以看出，分析结果给出了：

函数运行时间百分比
函数运行的总时间（不包括子函数）
函数运行总时间（包括子函数）
调用次数
函数平均调用时间（不包括子函数）
函数平均调用时间（包括子函数）
函数名称

整个列表默认按照函数运行总时间（包括子函数）排序。

从上面的结果可以得出一些结论：

最耗时的调用为 xor_calc()，调用次数为 8 次，总时间为 35.73s，平均调用一次的时间为 4.47s，占总时间的 100.5%（此处统计有误，猜测是浮点数精度引起）。
调用 time_cost1()和 time_cost2()分别耗时 13.40s 和 22.33s，其中包括调用子函数的时间，如果除去子函数调用，则为 0s。

接下来看第二个部分：调用图。

      Call graph

granularity: each sample hit covers 2 byte(s) for 0.03% of 35.73 seconds
index % time    self  children    called     name                                   1             main [1]                0.00   35.73       1/1           __libc_csu_init [3][1]    100.0    0.00   35.73       1+1       main [1]                0.00   22.33       1/1           time_cost2() [4]                0.00   13.40       1/1           time_cost1() [5]                                   1             main [1]-----------------------------------------------               13.40    0.00       3/8           time_cost1() [5]               22.33    0.00       5/8           time_cost2() [4][2]    100.0   35.73    0.00       8         xor_calc() [2]-----------------------------------------------                                                 <spontaneous>[3]    100.0    0.00   35.73                 __libc_csu_init [3]                0.00   35.73       1/1           main [1]-----------------------------------------------                0.00   22.33       1/1           main [1][4]     62.5    0.00   22.33       1         time_cost2() [4]               22.33    0.00       5/8           xor_calc() [2]-----------------------------------------------                0.00   13.40       1/1           main [1][5]     37.5    0.00   13.40       1         time_cost1() [5]               13.40    0.00       3/8           xor_calc() [2]-----------------------------------------------Index by function name
   [5] time_cost1()            [2] xor_calc()   [4] time_cost2()            [1] main

复制代码

和第一部分一样，上面部分是分析结果，下面部分是说明。

这部分结果给出了函数的调用关系。

左侧为函数唯一标号（由gprof自动生成），右侧的每一列代表：此函数与其子函数消耗的时间战程序运行时间的百分比、此函数消耗时间、子函数消耗时间、调用次数、调用关系。

举例说明，我们看第 4 行的内容：

                0.00   22.33       1/1           main [1][4]     62.5    0.00   22.33       1         time_cost2() [4]               22.33    0.00       5/8           xor_calc() [2]

复制代码

可以得出以下结果：

函数标号为 4，从右侧可以看出,4 标号代表函数time_cost2
占用运行总时间 62.5%
调用关系为main->time_cost2->xor_calc
main自身消耗 0s，子函数消耗 22.33s
time_cost2自身消耗 0s，子函数消耗 22.33s
xor_calc自身消耗 22.33s，子函数消耗 0s
xor_calc一共被调用 8 次，此处被调用 5 次。

从以上结果可以大致分析出程序的性能瓶颈是在xor_calc函数（事实上只有此函数耗时）。

常用参数

-b：这也是我们常用参数之一，此参数会省略冗长的列信息解释，如果不加此参数，在输出分析结果表格的同时，还会输出每一列的详细解释，如果已经熟悉gprof工具的使用，就可以使用此参数使输出更加简洁。

-C：此参数输出每个函数的调用次数，-C后面也可以跟上函数名称（编译后的名称）来打印指定函数的调用次数。上节的例子使用-C参数的输出为:

<unknown>:0: (_Z8xor_calcv:0x86a) 8 executions<unknown>:0: (_Z10time_cost1v:0x89e) 1 executions<unknown>:0: (_Z10time_cost2v:0x8c7) 1 executions<unknown>:0: (_Z41__static_initialization_and_destruction_0ii:0x90b) 1 executions<unknown>:0: (_GLOBAL__sub_I__Z8xor_calcv:0x95a) 1 executions

复制代码

-p:仅打印性能分析结果，不打印调用图。

-q:仅打印调用图，不打印性能分析结果。

-a:不打印“私有函数”，这里的“私有”是指static修饰的局部函数。

以上为几个常用参数，想要了解更详细的参数介绍，可以使用man查看：

man gprof

复制代码

需要注意的地方

gprof可以用来分析程序运行的情况，但是有一些地方需要注意。

递归的处理
gprof以函数为单位，所以递归调用会被认为是在同一函数内部。
计时并不精确
gprof使用秒作为计时单位（虽然后面有小数点，但也最多精确到毫秒），所以对时间的统计并不准确，比如对一些执行时间短的函数直接计算为运行时间为 0。虽然计时并不精确，但各函数调用的时间比例大致准确，所以对程序优化仍有很强的参考意义。
不支持多线程
gprof只能分析主线程的函数调用情况，对于其他线程无能为力。不过这个问题通常可以通过编写单元测试，对程序的每一部分分别做性能分析。

gprof对于一般小程序的性能分析差不过够用了，如果需要更专业的工具，可以试试valgrind。valgrind中的callgrind相比gprof更精细、更专业。

发布于: 刚刚

原文链接:【http://xie.infoq.cn/article/8e0a743bb2b6f7367559b9757】。文章转载请联系作者。

SkyFire

关注

还未添加个人签名 2018.10.13 加入

还未添加个人简介

发布

暂无评论

创作场景

使用 gprof 进行简单程序的性能分析

使用gprof进行简单程序的性能分析

简介

使用方法

例子

常用参数

需要注意的地方

SkyFire

评论

使用`gprof`进行简单程序的性能分析