Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
42.06 0.05 0.05 2 25.23 25.23 f()
33.64 0.09 0.04 1 40.37 65.61 g()
25.23 0.12 0.03 main
0.00 0.12 0.00 1 0.00 0.00 _GLOBAL__sub_I__Z1fv
0.00 0.12 0.00 1 0.00 0.00 __static_initialization_and_destruction_0(int, int)
% time:各个函数占用的时间比率(不包括子函数),这一列加起来应该为100%
cumulative seconds:累积时间,当前行减去上一行即为当前函数耗费时间
self seconds:当前函数耗费时间(不包括子函数)
self calls:调用次数
ms/call:调用一次耗费的平均时间(不包括子函数),单位毫秒
total ms/call:同上,但包括子函数
name:函数名
可将gprof -b ./hello中的-b参数去掉,可以显示字段的详细含义描述
Call graph
granularity: each sample hit covers 2 byte(s) for 8.26% of 0.12 seconds
index % time self children called name
[1] 100.0 0.03 0.09 main [1]
0.04 0.03 1/1 g() [2]
0.03 0.00 1/2 f() [3]
-----------------------------------------------
0.04 0.03 1/1 main [1]
[2] 54.2 0.04 0.03 1 g() [2]
0.03 0.00 1/2 f() [3]
-----------------------------------------------
0.03 0.00 1/2 g() [2]
0.03 0.00 1/2 main [1]
[3] 41.7 0.05 0.00 2 f() [3]
-----------------------------------------------
0.00 0.00 1/1 __libc_csu_init [16]
[8] 0.0 0.00 0.00 1 _GLOBAL__sub_I__Z1fv [8]
0.00 0.00 1/1 __static_initialization_and_destruction_0(int, int) [9]
-----------------------------------------------
0.00 0.00 1/1 _GLOBAL__sub_I__Z1fv [8]
[9] 0.0 0.00 0.00 1 __static_initialization_and_destruction_0(int, int) [9]
-----------------------------------------------
Index by function name
[8] _GLOBAL__sub_I__Z1fv (hello.cpp) [2] g() [1] main
[3] f() [9] __static_initialization_and_destruction_0(int, int) (hello.cpp)
每个函数都分配了一个index,index按升序排列,一个函数对应一个entry,两个entry之间用虚线隔开。
在每个entry中,以[index]起头的行称为primary line。primary line上面的行称为caller's line,列举的是调用该函数的函数;下面的行subroutine's line列举的是该函数调用的子函数。这三种line的各项名称虽然相同,但有着截然不同的含义。
以下都以第二个entry为例说明:
primary line
index % time self children called name
[2] 53.6 0.04 0.04 1 g() [2]
%time:g()耗费的时间比率。该比率包括了调用的f(),因此各个entry的该项数字加起来不等于100%。
self:同flat table的self seconds。
children:f()耗费的时间。下面的subroutines's line 的self项和children项之和应等于该数值。
called:只被调用了一次。
subroutine's line
index % time self children called name
0.04 0.00 1/2 f() [3]
self:f()被g()调用过程中,f()的耗费时间0.04s。
children:f()被g()调用过程中,f()中的子函数耗费时间为0。
called:f()一共被调用了2次,其中有1次被g()调用。
caller's line
index % time self children called name
0.04 0.04 1/1 main [1]
self:g()被main()调用过程中,g()的耗费时间。
children:g()被main()调用过程中,g()中的子函数耗费的时间。
called:g()一共被调用了1次,其中1次是被main()调用的。