使用gprof奇怪的分析输出

我目前正在使用gprof分析我的代码，该代码符合C99。 我的程序是递归定义的 。 我正在编译使用带有-pg标志的gcc，并启用了一些警告，并且没有优化标志。 然后我运行代码，然后执行命令：

gprof ./myProgram > outputFile.txt

不过，我对输出结果告诉我很困惑。 这是说，我花了很多时间在一个函数中，我知道这个函数我没有花太多时间。有问题的函数有一个循环，并且执行一个任务多次。 然而，这是一项小任务，并且通过将任务完成的次数从5比100增加到100，我的程序执行所花费的总时间没有发生明显变化。 然而，gprof告诉我，我已经花费了将近50％的执行时间在这个函数中。

我不知道这里的问题是什么。 有没有人遇到过这样的事情？ 我能自己解决这个问题吗？ 我正在使用Linux的CentOS发行版。 我曾尝试将OProfile安装为另一个配置文件，但没有对/ usr / local的写入权限，因此make install失败，因此不确定这是否只是gprof的问题

以下是输出文件的相关部分。 奇怪的输出是函数nl_jacobi_to_converge ：

从我拥有的平面轮廓

  %   cumulative   self              self     total           
 time   seconds   seconds    calls   s/call   s/call  name    
 49.02      7.50     7.50     1562     0.00     0.01  calculate_resid_numeric_jac_diags_tc41
 16.41     10.01     2.51 323878716     0.00     0.00  c
 14.97     12.30     2.29 323878716     0.00     0.00  b
  6.01     13.22     0.92       89     0.01     0.02  calculate_resid_tc41
  5.69     14.09     0.87 10967082     0.00     0.00  rhs_function
  1.11     14.26     0.17     1562     0.00     0.00  single_nl_jacobi
  ...
  0.00     15.30     0.00       11     0.00     0.76  nl_jacobi_to_converge

从我拥有的粒度来看

index % time    self  children    called     name
                0.00    8.32      11/11          nl_multigrid [3]
[5]     54.4    0.00    8.32      11         nl_jacobi_to_converge [5]
                5.28    2.92    1100/1562        calculate_resid_numeric_jac_diags_tc41 [4]
                0.12    0.00    1100/1562        single_nl_jacobi [17]

---

你是众多试图找出gprof告诉他们的人之一，小数点后四位。 我使用随机暂停和检查堆栈。

首先， gprof是一个“CPU分析器”。 这意味着在IO，互斥锁，分页或任何其他阻塞系统调用期间，它将被关闭，并且不会计算该时间。 你说你没有这样做，但它可能发生在一些库函数内部。 如果是这样， gprof掩盖它。 另一方面，一个堆栈样本将显示它正在等待什么，其概率等于它正在等待的时间的一小部分。

其次，正如@凯瑟琳所说的，了解“自我时间”很重要。 如果它很高，那意味着程序计数器在该例程中占用CPU时间的很大百分比。 但是，如果它很低，那并不意味着该功能无罪。 该函数可能花费大量时间，但通过调用子函数来完成。 要看到这一点，你需要gprof “total”列，但占总时间的百分比，而不是每次调用的绝对时间，这是它给你的。 如果你拿一个堆栈样本，那么任何例程都会以等于它花费的时间的概率出现在它上面。 更重要的是，您将确切知道为什么这段时间会花费，因为样本会告诉您发生呼叫的确切线路号码。

补充： gprof尝试处理递归函数，但正如其作者指出的那样，它不成功。 但是，栈递归在递归方面没有问题。 如果在递归函数调用期间获取堆栈样本，该函数可能多次出现在堆栈上多次。 然而，函数的包含时间成本，或任何调用函数的代码行，只不过是它在堆栈上的时间的一小部分。 为了看到这一点，假设以恒定频率采样，总共有M个样本，并且在它们的小数F上出现了特定函数或代码行。 如果这个功能或者代码行可以不花时间，比如删除它，分支它，或者把它传递给一个无限快的处理器，那么它就没有被采样的风险。 然后，它出现的M * F样本将消失，缩短执行时间F部分。

---

“自我”时间实际上是在该函数的代码中花费的时间。 “累积”时间是在该函数以及函数调用的任何事物（自我加上孩子）中花费的时间。

请注意，百分比是测量时间的百分比。 一个运行很多次的函数（比如你的b ）显然会影响运行时，而不仅仅是一个只运行几次的函数（你的n1_jacobi_to_converge ）。 每次通话所花的时间（ /call ）可能太小而无法报告，但总数仍可能很大，并且可能仍然表明，值得寻找方法来减少通话次数和/或提高每次调用的效率。

警告：JIT稳定之前的测量毫无意义。 而且由于JIT不确定性，特别是但不仅限于大型多线程应用程序，即使Java代码未更改，性能也可能会因运行而大幅度变化。 在测量之前进行多次测量，并进行足够的预热，甚至准备妥善检查分析器的建议，因为它们可能会引起误解。

另一个警告：检查信号量等待时间是否被测量，并确保你知道所有线程中发生了什么。 如果您不计算等待时间，您可能会错过不在您的直接调用堆栈中的性能瓶颈。

（我花了很多时间优化了Apache Xalan及其IBM内部的后代，在那里，我们也有代码生成，它有自己的不确定性，最初的性能改进很简单明显;之后它变得更加复杂具有挑战性的！）

链接地址: http://www.djcxy.com/p/7627.html

上一篇: Weird profiling output using gprof

下一篇: Seeking maximum bitmap (aka bit array) performance with C/Intel assembly