gprof & line-by-line profiling

gprof介绍及功能

gprof是GNU profile工具，可以运行于linux、AIX、Sun等操作系统进行C、C++、Pascal、Fortran程序的性能分析，用于程序的性能优化以及程序瓶颈问题的查找和解决。通过分析应用程序运行时产生的“flat profile”，可以得到每个函数的调用次数，每个函数消耗的处理器时间，也可以得到函数的“调用关系图， call gragh”，包括函数调用的层次关系，每个函数调用花费了多少时间。

使用步骤

（1）1) 用gcc、g++、xlC编译程序时，使用-pg参数，如：g++ -pg -o test.exe test.cpp
编译器会自动在目标代码中插入用于性能测试的代码片断，这些代码在程序运行时采集并记录函数的调用关系和调用次数，并记录函数自身执行时间和被调用函数的执行时间。
2) 执行编译后的可执行程序，如：./test.exe。该步骤运行程序的时间会稍慢于正常编译的可执行程序的运行时间。程序运行结束后，会在程序所在路径下生成一个缺省文件名为gmon.out的文件，这个文件就是记录程序运行的性能、调用关系、调用次数等信息的数据文件。
3) 使用gprof命令来分析记录程序运行信息的gmon.out文件，如：gprof test.exe gmon.out则可以在显示器上看到函数调用相关的统计、分析信息。上述信息也可以采用gprof test.exe gmon.out> gprofresult.txt重定向到文本文件以便于后续分析。

C语言版本对应gcc的gprof使用步骤总结(重点)

Step 1: gcc -pg test.c -o test
(结果：生成新的名为test的可执行文件)
Step 2: 运行test: ./test
(结果：此时生成新的文件，名为gmon.out，该文件内记载了所有有关该程序的运行时性能信息及函数关系，调用次数等信息)
Step 3: 使用gprof命令来分析 记录程序运行信息 的gmon.out文件： gprof test [gmon.out]
（结果：显示器上看到函数调用相关的统计、分析信息）
此外，如果使用：gprof test [gmon.out] > gprofresult.txt，会重定向到文本文件以便于后续分析。

Line-by-line Profiling (gprof -l) (很重要！！！)

一行接着一行的进行性能分析。
有时会遇到一个问题，只有main函数，导致main函数占100%，无法测量具体某个部分的性能，怎么办？ 使用line-by-line profiling, 通过参数-l 从而可以对每一行语句进行性能分析，从而发现影响性能的部分：
Q: When I run gprof the results always show that 100% of the time is spent in the main() function, regardless of the size of the grid?
A: If you have a program that reads in a very large file using a function called read_data(), for example, and this function takes 9 minutes, and then the contents of the file are processed in a function process_data(), for example, which takes 1 minute, then the profiler will show that 90% of the execution is in read_data().
For the Percolate program, most of the code is in main(), so it is not particularly surprising that 100% of the time is spent in in main(). You might find line-by-line profiling useful: https://ftp.gnu.org/old-gnu/Manuals/gprof-2.9.1/html_node/gprof_17.html#SEC17.

根据官网：
line-by-line profiling 标志: gprof test gmon.out -l

1. In this mode, histogram samples are assigned not to functions, but to individual lines of source code.
2. The program usually must be compiled with a “-g” option, in addition to “-pg”, in order to generate debugging symbols for tracking source code lines.
3. The flat profile is the most useful output table in line-by-line mode. The call graph isn’t as useful as normal, since the current version of gprof does not propagate call graph arcs from source code lines to the enclosing function. The call graph does, however, show each line of code that called each function, along with a count.

举例

Here is a section of gprof’s output, without line-by-line profiling. Note that ct_init accounted for four histogram hits, and 13327 calls to init_block.

Now let’s look at some of gprof’s output from the same program run, this time with line-by-line profiling enabled. Note that ct_init’s four histogram hits are broken down into four lines of source code - one hit occured on each of lines 349, 351, 382 and 385. In the call graph, note how ct_init’s 13327 calls to init_block are broken down into one call from line 396, 3071 calls from line 384, 3730 calls from line 385, and 6525 calls from 387.

样例：

基本模式补充（默认情况下不加参数全部都有）

Flat profile模式 (gprof -p)

使用 gprof 命令分析gmon.out 文件，如下所示：

gprof test gmon.out -p

-p参数标识“flat profile”模式，在分析结果中不显示函数的调用关系，AIX平台默认此参数有效。
输出以下内容：
清单 2. flat profile 的结果
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
80.38 203.27 203.27 50000 4.07 4.07 b
19.61 252.87 49.60 50000 0.99 0.99 a
0.00 252.88 0.01 main

上面结果中各个列的含义如下：
%time 函数以及衍生函数（函数内部再次调用的子函数）所占的总运行时间的百分比
cumulative seconds 函数累计执行的时间
self seconds 函数执行占用的时间
calls 函数的调用次数
self ms/call 每一次调用函数花费的时间microseconds，不包括衍生函数的运行时间
total ms/call 每一次调用函数花费的时间microseconds，包括衍生函数的运行时间
name 函数名称
列的含义，在gprof的输出结果中都有详细的说明。
从输出结果中可以看到，正如我们期望的一样，b 函数所花费的时间大概是 a 函数所花费的时间的 4倍。
很多函数调用（例如 printf）在上面的输出结果中都没有出现。这是因为大部分函数都是在C链接库（libc.so）中，而链接库并没有使用 -pg 进行编译，因此就没有对链接库中的函数收集调度信息。

call graph模式 (gprof -q)

如果希望反映函数之间的调用关系，需要采用如下命令：

gprof example1 gmon.out –q

-q参数标识“call graph”模式，在分析结果中显示函数的调用关系。
输出以下内容：
清单 3. Call graph
granularity: each sample hit covers 4 byte(s) for 0.00% of 252.72 seconds

index % time self children called name

[1] 100.0 0.00 252.72 main [1]
201.41 0.00 50000/50000 b [2]
51.31 0.00 50000/50000 a [3]
-----------------------------------------------
201.41 0.00 50000/50000 main [1]
[2] 79.7 201.41 0.00 50000 b [2]
-----------------------------------------------
51.31 0.00 50000/50000 main [1]
[3] 20.3 51.31 0.00 50000 a [3]
-----------------------------------------------
上面结果中各个列的含义如下：
index 每个函数第一次出现时都分配了一个编号，根据编号可以方便的查找函数的具体分析数据
%time 函数以及衍生函数（函数内部再次调用的子函数）所占的总运行时间的百分比
self 函数的总运行时间
children 衍生函数执行的总时间
called 函数被调用的次数，不包括递归调用
name 函数名称
在name列中，可以看出函数之间的调用关系，main函数调用a、b函数，b函数被main函数调用，a函数被main函数调用。通过函数名称后面的数字来标识这个文件中的函数，从而可以快速定位函数的分析数据的位置，经过一层层的逐步深入的分析就得到各个函数的调用关系以及各个函数的性能数据。

Reference

[1] https://www.cnblogs.com/andashu/p/6378000.html