对gprof的补充1(已经摘抄)

我的原文如下:
http://blog.chinaunix.net/u1/34500/showart_2144110.html

gprof
[功能]
gprof可以用来分析程序的性能.

[描述]
常用的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 显示使用次数为零的例程(按照调用计数和累积时间计算)。

[举例]

关于gprof工具输出数据的含义解释:


假设有一个程序源文件hello.c内容如下:


#include <stdio.h>


static void my_print (char *);

static void my_print2 (const char *);


main ()

{

char my_string[] = "hello world!";

my_print (my_string);

my_print2 (my_string);

my_print (my_string);

}


void count_sum()

{

int i,sum=0;

for(i=0; i<10000000; i++)

sum += i;

}


void my_print (char *string)

{

count_sum();

printf ("The string is %s ", string);

}

void my_print2 (const char *string)

{

char *string2;

int size, i,sum =0;

count_sum();

size = strlen(string);

string2 = (char *) malloc (size + 1);

for (i = 0; i < size; i++) string2[size -1 - i] = string;

string2[size] = '\0';

for(i=0; i<50000000; i++)

sum += i;


printf ("The string printed backward is %s ", string2);

}


1)编译生成可执行程序hello:

gcc -pg -o hello hello.c

2)需要运行一下可执行程序hello以生成gprof分析需要的数据:

$./hello

这样,会生成一个gmon.out文件供 gprof分析程序时候使用。

3)开始分析程序的执行时间:

$gprof hello

输入之后,生成如下:

【片断一】

Flat profile:



Each sample counts as 0.01 seconds.

% cumulative self self total

time seconds seconds calls us/call us/call name

69.23 0.09 0.09 1 90000.00 103333.33 my_print2

30.77 0.13 0.04 3 13333.33 13333.33 count_sum

0.00 0.13 0.00 2 0.00 13333.33 my_print


这里,描述了所有函数的执行消耗情况,每一行将代表一个函数,每一列的标题占两行,含义如下:

%

time

时间百分比,表示执行此函数所占用的时间占程序总执行时间百分比(不含其调用函数的执行时间)


cumulative

seconds (包括此函数调用其它函数花费的时间)

累计秒数,表示执行此函数花费的时间(所有次执行的时间总和,不含其调用函数的执行时间)



self 执行此函数花费的时间

seconds (调用其它函数花费的时间不计算在内)

此函数秒数,表示每次执行此函数花费的时间(仅一次执行,不含其调用函数的执行时间)



calls

调用次数,表示此函数被调用了多少次



self

us/call

此函数微妙数,表示每次调用此函数平均消耗的微秒时间(不包含此函数调用的子函数消耗时间)。


total

us/call

总微妙数,表示每次调用此函数平均消耗的总共微秒时间(包含此函数调用的子函数消耗时间)。


name

函数名


【片断二】

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

<spontaneous>

[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字段打印一个`<spontaneous>'字符,并且所有其它字段为空(例如第一行)。

对于记录中当前行下面行(子函数)来说,代表子函数名加其记录的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]

-----------------------------------------------

<spontaneous>

[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]

-----------------------------------------------

这里的fact就是阶乘的递归调用,代码我省略了。


--------

这里红字部分了解的不透彻,不透彻所以看不懂,有谁能指导一下吗?



补充一下,cumulative seconds实际是:一个时间和,它的原始解释如下:

cumulative a running sum of the number of seconds accounted

seconds for by this function and those listed above it.

也就是说,第一行的self=cumulative

以后行的cumulative=self+上一行的cumulative

再补充一点,对于文中的红色"?",这样理解:

从某个函数A的子函数B返回到那个函数A所花费的时间,实际就是那个函数A在直接调用B、执行完B本身的代码(不含B的子函数)、并且返回A,这样的情况下所消耗的时间。

从某个函数A的子函数B的子函数C返回到那个函数所花费的时间,实际就是那个函数在调用B这个函数的时候、执行除了B之外的B函数的子孙C、最后返回到A所花费的时间。

说的似乎很复杂,实际直接看图自己理解,是很简单的,不要以为这个工具的输出有多么复杂,要以简单的思想来分析它的输出含义。
  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值