令人困惑的gprof输出

Question

根据time()的说法，我在一个采用16.637s的C++程序上运行了gprof，得到的第一行输出是这样的：

%   cumulative   self              self     total           
time   seconds   seconds    calls   s/call   s/call  name    
31.07      0.32     0.32  5498021     0.00     0.00  [whatever]

如果只需要.32秒，为什么它会列出31.07% of time？这是每次调用的时间吗？(这不就是self s/call吗？)

这是我第一次使用gprof，所以请多多关照:)

编辑:通过向下滚动，gprof似乎认为我的程序只需要1.03秒。为什么它会搞错呢？

Answer 1

瓶颈最终出现在文件I/O (请参阅Is std::ifstream significantly slower than FILE?)。我切换到读取缓冲区中的整个文件，它的速度非常快。

这里的问题是，在等待文件I/O时，gprof似乎不能生成准确的分析(参见http://www.regatta.cs.msu.su/doc/usr/share/man/info/ru_RU/a_doc_lib/cmds/aixcmds2/gprof.htm)。事实上，seekg和tellg甚至不在分析列表中，它们是瓶颈！

Answer 2

Self seconds是花费在任何东西上的时间。

累计秒数是花费在and和上面的调用上的时间(例如and+ main)

，，这就是为什么你看不到更多时间列表的原因。

例如，如果你的函数调用了很多printf，那么你的gprof输出就会告诉你printf消耗了大部分时间。

Answer 3

这似乎是对how to read gprof output的一个很好的概述。您正在查看的31.07%是gprof认为仅在该函数(不包括它调用的函数)上花费的总运行时间的一部分。gprof认为程序不会像你那样花费很长的时间，这就是为什么百分比这么大而时间却很小的原因。这很容易通过向下滚动gprof输出的第一部分来检查:累积秒数将会越来越大，直到它限制到程序的总运行时间(从gprof的角度来看)。我想你会发现这大约是1秒，而不是你预期的16秒。

至于为什么会有这么大的差异，我不能说。也许gprof并没有看到所有的代码。或者，在分析代码的过程中，您是否使用了时间？我不期望它能正常工作...