GNU gprof分析C性能

参考

gprof的简单使用-anthony1983-ChinaUnix博客

Top (GNU gprof) (sourceware.org)

c - Enable and disable gprof at runtime? - Stack Overflow

gprof——GNU性能分析工具 - feisky - 博客园 (cnblogs.com)

Linux性能优化gprof使用 - youxin - 博客园 (cnblogs.com)

gprof介绍

GNU分析工具gprof可以有用的测量程序的性能,它记录了调用每个函数的次数以及在每个函数上花费的时间。

从gprof的输出可以容易的看出占用大量运行时间的函数。提高程序运行速度应该首先集中在那些占据费时的函数上。

使用方式

gprof [可执行文件] [gmon.out文件] [其它参数]

方括号中的内容可以省略。如果省略了“可执行文件”,gprof会在当前目录下搜索a.out文件作为可执行文件;

如果省略了gmon.out文件,gprof也会在当前目录下寻找gmon.out。

其它参数可以控制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:显示使用次数为零的例程(按照调用计数和累积时间计算)。

使用步骤

  1. 使用gcc/g++编译时,加参数-pg,比如gcc -pg -o test test.c
  2. 运行编译好的程序test,程序会产生gmon.out文件
  3. 使用gprof工具分析gmon.out文件,gprof ./test gmon.out。

测试代码:

#include <stdio.h>

/* Computes the length of Collatz sequences */
unsigned int step(unsigned int x)
{
    if (x % 2 == 0) {
        return (x / 2);
    } else {
        return (3 * x + 1);
    }
}

unsigned int nseq(unsigned int x0)
{
    unsigned int i = 1, x;
    if (x0 == 1 || x0 == 0)
        return i;
    x = step(x0);
    while (x != 1 && x != 0) {
        x = step(x);
        i++;
    }
    return i;
}

int main(void) 
{
    unsigned int i, m = 0, im = 0;
    for (i = 1; i < 500000; i++) {
        unsigned int k = nseq(i);
        if (k > m) {
            m = k;
            im = i;
            printf("sequence length = %u for %u\n", m, im);
        }
    }
    return 0;
}

编译、运行、测试:

$ gcc -pg -o gprof_test gprof_test.c
$ ./gprof_test
$ gprof ./gprof_test gmon.out -b
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ns/call  ns/call  name
 75.82      0.30     0.30 62135400     4.88     4.88  step
 20.22      0.38     0.08   499999   161.76   768.35  nseq
  2.53      0.39     0.01                             frame_dummy
  2.53      0.40     0.01                             main

                        Call graph


granularity: each sample hit covers 2 byte(s) for 2.47% of 0.40 seconds

index % time    self  children    called     name
                                                   <spontaneous>
[1]     97.5    0.01    0.38                       main [1]
                0.08    0.30  499999/499999        nseq [2]
-----------------------------------------------
                0.08    0.30  499999/499999  	   main [1]
[2]     95.0    0.08    0.30  499999         	   nseq [2]
                0.30    0.00 62135400/62135400     step [3]
-----------------------------------------------
                0.30    0.00 62135400/62135400     nseq [2]
[3]     75.0    0.30    0.00 62135400              step [3]
-----------------------------------------------
                                                   <spontaneous>
[4]      2.5    0.01    0.00                       frame_dummy [4]
-----------------------------------------------

Index by function name

   [4] frame_dummy             [2] nseq
   [1] main                    [3] step

测试结果

  • % time:当前函数占总的运行时间的百分比
  • cumulative seconds:函数和上列函数累计执行的时间,单位秒
  • self seconds:函数本身执行的时间
  • calls:函数被调用次数
  • self ms/call:每一次调用花费在函数的时间
  • total ms/call:每一次调用,花费在函数及其依赖函数的平均时间
  • name:函数名
$ gprof ./gprof_test gmon.out -b
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ns/call  ns/call  name
 75.82      0.30     0.30 62135400     4.88     4.88  step
 20.22      0.38     0.08   499999   161.76   768.35  nseq
  2.53      0.39     0.01                             frame_dummy
  2.53      0.40     0.01                             main

Call graph 信息解释:

  • index:索引值
  • % time:函数消耗时间占所有时间百分比
  • Self:函数本身执行时间
  • Children:执行子函数所用时间
  • Called:被调用次数
  • Name:函数名
index % time    self  children    called     name
                                                   <spontaneous>
[1]     97.5    0.01    0.38                       main [1]
                0.08    0.30  499999/499999        nseq [2]
-----------------------------------------------
                0.08    0.30  499999/499999  	   main [1]
[2]     95.0    0.08    0.30  499999         	   nseq [2]
                0.30    0.00 62135400/62135400     step [3]
-----------------------------------------------
                0.30    0.00 62135400/62135400     nseq [2]
[3]     75.0    0.30    0.00 62135400              step [3]
-----------------------------------------------
                                                   <spontaneous>
[4]      2.5    0.01    0.00                       frame_dummy [4]
-----------------------------------------------

Index by function name

   [4] frame_dummy             [2] nseq
   [1] main                    [3] step

缺点

  • 只能分析应用程序在运行过程中所消耗掉的用户时间,无法得到程序内核空间的运行时间。

    查看内核空间运行时间的方式,可以使用time命令:

    $ time ./test
    real    0m0.591s   实际运行时间
    user    0m0.498s  用户态运行时间
    sys     0m0.093s  内核态运行时间
    
  • 分析的执行时间不包括由于挂起和阻塞的时间,所以对于有大量阻塞调用和休眠挂起的程序,使用gprof进行分析,并不能很好的分析出程序瓶颈的所在。gprof以固定的周期对程序运行时间进行采样测量,当程序挂起时,gprof不会对程序进行采样测量。
    解决方式:如果只对某部分代码进行分析,可以在不需要进行分析的代码段调用moncontrol(0)关闭分析,然后在需要分析的代码段调用moncontrol(1)打开分析。

    extern void moncontrol(int);
    moncontrol(0);
    moncontrol(1);
    
  • 不支持动态库中的函数分析

posted @ 2023-06-02 21:16  zhengcixi  阅读(64)  评论(0编辑  收藏  举报
回到顶部