Chinaunix首页 | 论坛 | 博客
  • 博客访问: 182888
  • 博文数量: 74
  • 博客积分: 2521
  • 博客等级: 大尉
  • 技术积分: 730
  • 用 户 组: 普通用户
  • 注册时间: 2009-06-24 08:28
文章分类

全部博文(74)

文章存档

2012年(3)

2011年(14)

2010年(26)

2009年(31)

分类:

2009-12-03 09:49:43

gprof介绍
gprof是GNU profiler工具。可以显示程序运行的“flat profile”,包括每个函数的调用次数,每个函数消耗的处理器时间。也可以显示“调用图”,包括函数的调用关系,每个函数调用花费了多少时间。还可以显示“注释的源代码”,是程序源代码的一个复本,标记有程序中每行代码的执行次数。

基本用法:
1. 使用-pg选项编译和链接你的应用程序。
2. 执行你的应用程序,使之运行完成后生成供gprof分析的数据文件(默认是gmon.out)。
3. 使用gprof程序分析你的应用程序生成的数据,例如:gporf a.out gmon.out。

举例

gcc -Wall -pg -o test test.c               //程序文件名称 test.c 编译时使用 -pg

现在我们可以再次运行test,并使用我们前面使用的测试数据。这次我们运行的时候,test运行的分析数据会被搜集并保存在'gmon.out'文件中,我们可以通过运行 ' gprof test '来查看结果。

./test

gprof test


gprof 实现原理:
gprof并不神奇,在编译和链接程序的时 候(使用 -pg 编译和链接选项),gcc 在你应用程序的每个函数中都加入了一个名为mcount(or“_mcount”, or“__mcount”)的函数,也就是说-pg编译的应用程序里的每一个函数都会调用mcount, 而mcount会在内存中保存一张函数调用图,并通过函数调用堆栈的形式查找子函数和父函数的地址。这张调用图也保存了所有与函数相关的调用时间,调用次数等等的所有信息。

程序运行结束后,会在程序退出的路径下生成一个 gmon.out文件。这个文件就是记录并保存下来的监控数据。可以通过命令行方式的gprof或图形化的Kprof来解读这些数据并对程序的性能进行分析。

另外,如果想查看库函数的profiling,需要在编译是再加入“-lc_p”编译参数代替“-lc”编译参数,这样程序会链接libc_p.a 库,才可以产生库函数的profiling信息。如果想执行一行一行的profiling,还需要加入“-g”编译参数。

gprof产生的信息
%                        the percentage of the total running time of the
time                     program used by this function.
                           函数使用时间占所有时间的百分比。
cumulative          a running sum of the number of seconds accounted
seconds             for by this function and those listed above it.
                           函数和上列函数累计执行的时间。
self                    the number of seconds accounted for by this
seconds             function alone. This is the major sort for this
                          listing.
                          函数本身所执行的时间。
calls                   the number of times this function was invoked, if
                          this function is profiled, else blank.
                          函数被调用的次数
self                   the average number of milliseconds spent in this
ms/call               function per call, if this function is profiled,
                         else blank.
                          每一次调用花费在函数的时间microseconds。
total                  the average number of milliseconds spent in this
ms/call               function and its descendents per call, if this
                          function is profiled, else blank.
                          每一次调用,花费在函数及其衍生函数的平均时间microseconds。
name                 the name of the function. This is the minor sort
                          for this listing. The index shows the location of
                          the function in the gprof listing. If the index is
                          in parenthesis it shows where it would appear in
                          the gprof listing if it were to be printed.
                          函数名

更多详细介绍

1. 在内存中分配一些内存,存储程序执行期间的统计数据
2. 在GCC使用-pg选项编译后,gcc会在程序的入口处(main 函数之前)调用

    void monstartup(lowpc, highpc)

在每个函数的入口处调用

    void _mcount()

在程序退出时(在 atexit () 里)调用

    void _mcleanup()

    * monstartup:负责初始化profile环境,分配内存空间
    * _mcount: 记录每个函数代码的caller和callee的位置
    * _mcleanup:清除profile环境,保存结果数据为gmon.out,供gprof分析结果

3.在_mcount函数中跟踪程序的执行状况,记录程序代码的执行次数,时间等数据。

常用的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) 一般gprof只能查看用户函数信息。如果想查看库函数的信息,需要在编译是再加入“-lc_p”编译参数代替“-lc”编译参数,这样程序会链接libc_p.a库,才可以产生库函数的profiling信息。
2) gprof只能在程序正常结束退出之后才能生成程序测评报告,原因是gprof通过在atexit()里注册了一个函数来产生结果信息,任何非正常退出都不会执行atexit()的动作,所以不会产生gmon.out文件。如果你的程序是一个不会退出的服务程序,那就只有修改代码来达到目的。如果不想改变程序的运行方式,可以添加一个信号处理函数解决问题(这样对代码修改最少),例如:

    static void sighandler( int sig_no )
    {
    exit(0);
    }
    signal( SIGUSR1, sighandler );

当使用kill -USR1 pid 后,程序退出,生成gmon.out文件。
【片断二】
Call graph (explanation follows)
 
 
 
granularity: each sample hit covers 2 byte(s) for 3.95% of 0.25 seconds
 

index %time  self  children    called     name
                                                
[1]    100.0    0.00    0.25                 main [1]
                    0.16    0.03       1/1           my_print2 [2]
                    0.00    0.06       2/2           my_print [4]
-----------------------------------------------
                   0.16    0.03       1/1           main [1]
[2]     76.0    0.16    0.03       1         my_print2 [2]
                   0.03    0.00       1/3           count_sum [3]
-----------------------------------------------
                   0.03    0.00       1/3           my_print2 [2]
                   0.06    0.00       2/3           my_print [4]
[3]     36.0    0.09    0.00       3         count_sum [3]
-----------------------------------------------
                   0.00    0.06       2/2           main [1]
[4]     24.0    0.00    0.06       2         my_print [4]
                   0.06    0.00       2/3           count_sum [3]
-----------------------------------------------
 

*对于这个表(函数调用图),这个表描述了程序的函数调用关系,根据调用时间的大小对函数以及它的孩子们进行排序。
 

*对于这个表中的每一条记录(共4条记录),每条记录包含若干行。
 

*对于每一条记录中的行,
每一条记录中有一行(在最左面一列)被标上了index号,这一行的name列的函数就代表了本记录的当前函数;
每条记录内代表本记录函数的行之上的所有行,其name列的函数都是直接父函数(调用当前记录的函数的函数);
每条记录内代表本记录函数的行之下的所有行,其name列的函数都是直接子函数(被当前记录的函数调用的函数)。
 

*每一列,对于每一条记录来说的含义如下:
index
代表表中每一条记录的唯一的数字(键),标在该记录当前的函数所在行,根据数字大小顺序依次排列;
另外,每一个name列处的函数名字后面也紧跟着一个index号,代表该name的函数是属于哪个index值记录的当前函数。
% time,
代表记录中当前行函数及其所有子孙(?)孩子们所消耗的时间占程序总时间的百分比,由于有些函数被排除或者其他原因可能总和不是100%.
 

self
对于记录中当前函数行来说,代表执行本函数所消耗的时间(不包含它的所有子函数)。
对于记录中当前行上面行(父函数)来说,代表本函数返回到父函数花费了(父函数)多久的时间(不包括本函数的子函数所消耗的时间)。
对于记录中当前行下面行(子函数)来说,代表子函数返回到本函数花费了(本函数)多久的时间(不包括子函数的子函数所消耗的时间)。
 

children,
对于记录中当前函数行来说,代表本函数的所有子孙(?)函数返回到本函数所消耗(本函数)的时间。
对于记录中当前行上面行(父函数)来说,代表本函数所有子孙(?)返回到父函数,子孙们(?)消耗(父函数)的时间。
对于记录中当前行下面行(子函数)来说,代表子函数所有子孙(?)返回到本函数,那些子孙(?)消耗(本函数)的时间。
 

called,
对于记录中当前函数行来说,代表本函数被调用的次数,如果是递归函数则是非递归部分次数跟一个'+'号接递归调用次数。
对于记录中当前行上面行(父函数)来说,'/'左面代表该父函数调用该函数次数,'/'右面代表该函数总共被调用次数。
对于记录中当前行下面行(子函数)来说,'/'左面代表该函数调用该子函数次数,'/'右面代表该子函数总共被调用次数。
name
对于记录中当前函数行来说,代表当前函数名加上其所属记录的index号,若该函数是某调用环一员,则环号放在函数名和index号之间。
对于记录中当前行上面行(父函数)来说,代表父函数名加其记录的index号,若父函数是某调用环一员,则环号放在父函数和index号之间。如果函数的父函数无法确定,那么在name字段打印一个`'字符,并且所有其它字段为空(例如第一行)。
对于记录中当前行下面行(子函数)来说,代表子函数名加其记录的index号,若子函数是某调用环一员,则环号放在子函数和index号之间。
 
 
 
如果在调用图中存在任何环,那么会有一个记录来记录整个环。这个记录描述了环中谁做为谁的父函数调用了谁。环中,called字段'+'后指名了这个函数在环内部(递归)调用的次数,called字段其它部分(应该在+之前),指出环外函数对本函数的(非递归)调用次数。例如如下:
 

index % time    self  children    called     name
                    0.16    0.03       1/1           main [2]
[1]    100.0    0.16    0.03       1         my_print2 [1]
                    0.03    0.00       1/1           count_sum [3]
-----------------------------------------------
                                                
[2]    100.0    0.00    0.19                 main [2]
                    0.16    0.03       1/1           my_print2 [1]
                    0.00    0.00       1/1           fact [4]
-----------------------------------------------
                   0.03    0.00       1/1           my_print2 [1]
[3]     15.8    0.03    0.00       1         count_sum [3]
-----------------------------------------------
                                              10             fact [4]
                  0.00    0.00           1/1           main [2]
[4]      0.0    0.00    0.00       1+10      fact [4]
                                              10             fact [4]
-----------------------------------------------

 
阅读(1306) | 评论(0) | 转发(0) |
0

上一篇:gdb使用(转)

下一篇:vi命令详解【转】

给主人留下些什么吧!~~