Go profiler (pprof) 时序差异答案

【问题标题】：Go profiler (pprof) timing discrepancyGo profiler (pprof) 时序差异
【发布时间】：2017-02-23 03:53:06
【问题描述】：

当我使用 Linux 的 time 实用程序测量 Go 程序的运行时间时，我得到以下输出：

real    1m9.177s
user    7m1.788s
sys     0m39.016s

当我在 Go 的 pprof CPU 分析器中查看相同程序执行的输出时，我得到以下输出：

Entering interactive mode (type "help" for commands)
(pprof) top
143.32s of 176s total (81.43%)

pprof 从哪里得到这个 176 的数字？它既不是时钟时间也不是 CPU 时间。我正在运行这个程序，GOMAXPROCS 设置为 8，我觉得这与它有关。 pprof 究竟是如何测量运行时间的，为什么它与 linux 的 time 不同？

【问题讨论】：

标签： go runtime profiling gperftools

【解决方案1】：

time 实用程序和pprof 工具以不同的方式运行，应以不同的方式使用。不要试图调和它们。 time 测量程序的准确时间； pprof 测量函数和方法的相对时间。 pprof 是一个侵入性统计样本。启用 CPU 分析后，Go 程序每秒停止大约 100 次，并在当前执行的 goroutine 的堆栈上记录由程序计数器组成的样本。抽样是有成本的，结果是对实际人口的估计。

使用time 测量程序的整体实际 CPU 时间，即绝对时间。使用pprof 使用相对时间百分比来估计大部分时间花在函数和方法上的位置。 pprof 识别瓶颈。对于实际 CPU 时间，请使用 Go testing 包基准测试。

例如，见Profiling Go Programs:

通过使用 Go 的分析工具来识别和纠正特定的瓶颈，我们可以让 Go 循环查找程序运行一个顺序速度更快，使用的内存减少 6 倍。

【讨论】：

【解决方案2】：

这看起来像一些错误。可能是一些已知的错误。 pprof 为了输出 176s 所做的是将已知采样周期乘以采样数。它应该是相当准确的w.r.t。进程（系统 + 用户）花费的总 CPU 时间。

您的程序是否有可能通过子进程产生一些工作？这可能是解释差异的一种方式。

【讨论】：