Learning gprof

学习笔记

使用gprof进行性能分析非常方便,只需要在编译的时候增加一个-gp选项即可。

编译命令如下

g++ -Wall -pg test_gprof.c -o test_gprof

生成运行信息

gprof -b test_gprof gmon.out

加了-b选项可以去掉自带的说明(非常长。。。)

输出的东西可以重定向到文件里看,比如

gprof -b test_gprof gmon.out > out

为了看懂输出信息我改了一下代码,最后是这样的:

//test_gprof.c
#include<stdio.h>
#include<math.h>
void func3() {
    for(int i = 0; i < 1e8; i++);
    printf("\n Inside func3\n");
    return;
}
void func4() {
    for(int i = 0; i < 1e8; i++);
    func3();
    return;
}
void new_func1(void)
{
    printf("\n Inside new_func1()\n");
    int i = 0;
    func3();
    for(;i<1e8;i++);
    func3();
    func4();
    return;
}
void func1(void)
{
    printf("\n Inside func1 \n");
    int i = 0;

    for(;i<1e8;i++);
    new_func1();

    return;
}
void func5(int x) {
    if(x > 1e4) return;
    for(int i = 0; i < 1e4; i++) 
        int y = sqrt((double)x);
    func5(x + 1);
}
static void func2(void)
{
    printf("\n Inside func2 \n");
    int i = 0;

    for(;i<1e8;i++);
    func3();
    func5(0);
    return;
}

int main(void)
{
    printf("\n Inside main()\n");
    int i = 0;

    for(;i<1e8;i++);
    func1();
    func2();

    return 0;
}

这个里面相比reference增加了一些东西,比如递归调用,一个函数在多处被调用。。。

输出如下:

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls   s/call   s/call  name    
 38.65      0.90     0.90        4     0.22     0.22  func3()
 12.60      1.19     0.29                             main
 10.86      1.44     0.25        1     0.25     0.25  func5(int)
  9.99      1.67     0.23        1     0.23     1.35  func1()
  9.56      1.89     0.22        1     0.22     0.45  func4()
  9.56      2.12     0.22        1     0.22     0.70  func2()
  9.56      2.34     0.22        1     0.22     1.12  new_func1()


            Call graph


granularity: each sample hit covers 2 byte(s) for 0.43% of 2.34 seconds

index % time    self  children    called     name
                                                 <spontaneous>
[1]    100.0    0.29    2.05                 main [1]
                0.23    1.12       1/1           func1() [2]
                0.22    0.48       1/1           func2() [5]
-----------------------------------------------
                0.23    1.12       1/1           main [1]
[2]     57.7    0.23    1.12       1         func1() [2]
                0.22    0.89       1/1           new_func1() [3]
-----------------------------------------------
                0.22    0.89       1/1           func1() [2]
[3]     47.7    0.22    0.89       1         new_func1() [3]
                0.45    0.00       2/4           func3() [4]
                0.22    0.22       1/1           func4() [6]
-----------------------------------------------
                0.22    0.00       1/4           func4() [6]
                0.22    0.00       1/4           func2() [5]
                0.45    0.00       2/4           new_func1() [3]
[4]     38.4    0.90    0.00       4         func3() [4]
-----------------------------------------------
                0.22    0.48       1/1           main [1]
[5]     29.8    0.22    0.48       1         func2() [5]
                0.25    0.00       1/1           func5(int) [7]
                0.22    0.00       1/4           func3() [4]
-----------------------------------------------
                0.22    0.22       1/1           new_func1() [3]
[6]     19.1    0.22    0.22       1         func4() [6]
                0.22    0.00       1/4           func3() [4]
-----------------------------------------------
                               10001             func5(int) [7]
                0.25    0.00       1/1           func2() [5]
[7]     10.8    0.25    0.00       1+10001   func5(int) [7]
                               10001             func5(int) [7]
-----------------------------------------------


Index by function name

   [2] func1()                 [7] func5(int)              [1] main
   [4] func3()                 [3] new_func1()
   [6] func4()                 [5] func2()

这个东西怎么看呢?

首先是flat profile, 它显示了每个函数运行的时间。

从左到右各列分别是:这个函数所用运行时间的百分比,列表从上到下的累计时间,这个函数自身所用的总时间(不包括它调用的其他函数,但是调用的库函数是算在这个时间里的),这个函数被其他函数调用的次数(递归调用不算在内),单次调用该函数所用时间(不包括调用其他函数),单词调用该函数所用时间(包括调用的其他函数),函数名。

还有call graph

最右边是函数名,开始的若干行有缩进,表示调用该函数的函数(父函数),该函数的函数名顶格写,后面又是若干行带缩进的表示该函数调用的函数(子函数)。

相当于带有向边的一个图。

main函数没有被其他函数调用所以父函数是

每列从左到右表示:函数自身所用时间,子函数所用时间,调用次数。

调用次数

在父函数行表示:对应父函数调用了该函数几次/该函数总的调用次数。
该函数行表示:这个函数一共被调用了几次。
在子函数行表示:该函数调用了这个子函数几次/子函数被调用的总次数。

递归函数的调用次数里是把自身调用和其他函数调用分开算的。

reference

GPROF Tutorial – How to use Linux GNU GCC Profiling Tool

Post Directory

文章目录

  1. reference