使用gprof进行奇怪的分析输出

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

gprof ./myProgram > outputFile.txt 

不过,我对输出告诉我的内容感到非常困惑。 这是说我花了很多时间在一个我知道的函数中,我不会花很多时间。这个函数有一个循环内部并执行一定次数的任务。 但这是一项微不足道的任务,并且通过增加完成任务的次数,例如5到100,我的程序执行所花费的总时间没有明显变化。 但是,gprof告诉我,我已经花费了近50%的执行时间。

我不知道这里的问题是什么。 有没有人遇到过这样的事情? 我可以自己解决吗? 我正在使用CentOS的Linux发行版。 我曾尝试将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掩盖它。 另一方面,单个堆栈样本将显示它正在等待的内容,概率等于它等待的时间部分。

其次,正如@keshlam所说,了解“自我时间”非常重要。 如果它很高,那意味着程序计数器在该例程中找到了相当大的CPU时间百分比。 但是,如果它很低,那并不意味着该function无罪。 该function可能会花费大量时间,但通过调用子function来完成。 要看到这一点,你需要gprof “total”列,但需要占总时间的百分比,而不是每次调用的绝对时间,这是它给你的。 如果您采用堆栈样本,那么任何例程都会出现在其上,其概率等于其花费的时间部分。 更重要的是,您将确切知道为什么花费时间,因为样本将显示调用发生的精确行号。

ADDED: gprof尝试处理递归函数,但正如其作者指出的那样,它没有成功。 但是,堆栈样本对递归没有问题。 如果在递归函数调用期间获取堆栈样本,则该函数在堆栈上出现多次,可能多次。 但是,仍然存在这样的情况:函数或调用函数的任何代码行的包含时间成本只是它在堆栈上的时间的一小部分。 为了看到这一点,假设样本以恒定频率拍摄,总共M个样本,并且特定函数或代码行出现在它们的分数F上。 如果可以使该函数或代码行不花时间,例如通过删除它,在其周围分支,或将其传递给无限快速的处理器,则它将不会被采样。 然后它出现的M * F样本将消失 ,缩短执行时间F分数。

“自我”时间是在该函数的代码中实际花费的时间。 “累积”时间是在该函数中花费的时间和任何函数调用(自己加上孩子)。

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

警告:JIT稳定前的测量没有意义。 由于JIT是不确定的,特别是但不仅仅是在大型multithreading应用程序中,即使Java代码不变,性能也可能因运行而异。 在测量之前进行多次测量,并进行充分的预热,然后准备好检查剖析器的建议,因为它们可能会产生误导。

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

(我花了很多时间优化Apache Xalan及其IBM内部后代。在那里,我们还有代码生成涉及混合,它有自己的非确定性。最初的性能改进很容易和明显;之后它变得更多具有挑战性的!)