gprof

时间：2014-11-17 21:01:47 阅读：201 评论：0 收藏：0 [点我收藏+]

标签：des style http io color ar 使用 sp java

函数级耗时剖析。gprof不会说谎，仔细考虑下函数的实现细节。

准备工作

对单文件simulator.cpp编译
- 编译：g++ -g -pg simulator.cpp -o simulator.o
- 链接：g++ -pg simulator.o -o simulator

对于使用CMakeLists.txt的工程

add_definitions(-g -pg)
set_target_properties(simulator PROPERTIES LINK_FLAGS "-pg")  # 必须用""把-pg引起来
#只对执行文件有效，对库文件使用无效
#如果想对自己的库文件做相应的剖析，把所有源文件都放在add_executable中

我们可以使用-O2对编译文件优化,但是一定要加-g -pg。在我的测试中，效果很好。大家务必试试。

生成剖析文件

执行程序，会在当前文件目录下生成gmon.out剖析文件

./simulator #除非程序处理了中断，保证收到中断能正常退出时，才会生成gmon.out文件
导出可读的性能文件

gprof simulator gmon.out > perf.log

解读剖析文件

主要关注两部分：Flat profile与Call graph

Flat profile

simulator flag profile

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 25.37      3.81     3.81 71089134     0.00     0.00  shared_buffer::BufferInterface::WriteBuffer(BufferDescriptor const&)
  8.92      5.15     1.34 71089350     0.00     0.00  shared_buffer::BufferInterface::CopyBuffer(BufferDescriptor const&, SharedBuffer*)
  7.99      6.35     1.20 71089350     0.00     0.00  shared_buffer::SharedBuffer::AllocCell(int)
  5.16      7.13     0.78 71089062     0.00     0.00  GenerateTime(timeval&)

拿第5行来说

% time：该函数占总运行时间的8.92%
cumulative seconds：累积前面的函数调用，总时间为5.15秒
self seconds：自身使用1.34秒
calls：该函数被调用71089350次
self ms/call：(单位可能是s/ms/ns依据调用情况来决定)未知，可能是平均调用时间，求解
total ms/call：(单位可能是s/ms/ns依据调用情况来决定)未知，求解
name：那么的直观

当我们拿到这样的结果时，我们首先应该关注下排名靠前的函数（为什么这么耗时），其次关注调用次数最多的函数（为什么会调用这么多次），还有就是关注你目前想了解的函数是否符合预期（调用次数与时间）

Call graph

simulator‘s call graph

index % time    self  children    called     name
                                                 <spontaneous>
[1]     98.9    0.00   14.86                 main [1]
                0.26   14.47       1/1           RunLoader(shared_buffer::BufferInterface&) [2]
                0.00    0.11       1/1           shared_buffer::BufferInterface::BufferInterface(std::string const&) [24]
                0.00    0.02       1/1           shared_buffer::BufferInterface::~BufferInterface() [31]
-----------------------------------------------
                0.26   14.47       1/1           main [1]
[2]     98.0    0.26   14.47       1         RunLoader(BufferInterface&) [2]
                0.57   12.92 71089062/71089062     SendBuffer2(BufferInterface&, DataType, unsigned int, OMTime const&) [3]
                0.78    0.00 71089062/71089062     GenerateTime(timeval&) [10]
                0.17    0.00 71089134/71089134     omatrix::OMTime::OMTime(timeval const&) [22]
                0.03    0.00 71089134/71089145     omatrix::OMTime::~OMTime() [28]
                0.01    0.00      72/72          SendBuffer(BufferInterface&, DataType, unsigned int, OMTime const&) [36]
                0.00    0.00       4/4           rdtsc() [137]
-----------------------------------------------
                0.57   12.92 71089062/71089062     RunLoader(shared_buffer::BufferInterface&) [2]
[3]     89.8    0.57   12.92 71089062         SendBuffer2(BufferInterface&, DataType, unsigned int, OMTime const&) [3]
                3.81    9.11 71089062/71089134     shared_buffer::BufferInterface::WriteBuffer(BufferDescriptor const&) [4]
-----------------------------------------------

拿index为2的来说

index：目前关注的重点函数编号，我们可以每行的未端看到同样形式的编号
time：该函数及其子函数的总耗时百分比为98.0%
self：该函数自身耗时0.26秒，该值等于前面的Flat profile部分的self seconds。同时该值也等于此部分中调用该函数的self的和。
children：该函数调用的子函数耗时14.47，同时大家可以算算，其子函数的self+children总和等于该值。同时该值也等于此部分中调用该函数的children的和。
called：如果是当前函数，该值没有/分割，表明它被调用的次数；如果是父/子函数，前半部分表示涉及该调用栈的次数，后半部分表示该函数总的被调用次数
name：还是那么的直观

通过该部分我们可以非常直观的观察调用关系，看是否有函数的调用是自己未预期的。

gprof

标签：des style http io color ar 使用 sp java

原文地址：http://www.cnblogs.com/457220157-FTD/p/4104292.html

踩

(0)

评论一句话评论（0）

分享档案

更多>

2021年07月29日 (22)
2021年07月28日 (40)
2021年07月27日 (32)
2021年07月26日 (79)
2021年07月23日 (29)
2021年07月22日 (30)
2021年07月21日 (42)
2021年07月20日 (16)
2021年07月19日 (90)
2021年07月16日 (35)

周排行