在 Java 中分析本机方法 - 奇怪的结果答案

【问题标题】：Profiling native methods in Java - strange results在 Java 中分析本机方法 - 奇怪的结果
【发布时间】：2009-07-07 23:48:54
【问题描述】：

我一直在使用 Yourkit 8.0 分析在 Mac OS X（10.5.7，Apple JDK 1.6.0_06-b06-57）下运行的数学密集型应用程序，并注意到 CPU 分析结果中有一些奇怪的行为。

例如 - 我使用采样进行了分析运行，它报告应用程序的 10 分钟运行时间中有 40% 用于 StrictMath.atan 方法。我觉得这很令人费解，但我信以为真，花了一些时间用一个极其简单的多项式拟合替换 atan。

当我再次运行该应用程序时，它所用的时间几乎与以前完全相同（10 分钟） - 但我的 atan 替换在分析结果中没有出现。相反，其他主要热点的运行时间百分比只是增加来弥补。

总结一下：

StrictMath.atan 的结果（本机方法）
总运行时间：10 分钟
方法一：20%
方法二：20%
方法三：20%
StrictMath.atan：40%

使用简化的纯 Java atan 的结果
总运行时间：10 分钟
方法一：33%
方法二：33%
方法三：33%

（方法 1,2,3 不执行任何 atan 调用）

知道这种行为是怎么回事吗？我使用 EJ-Technologies 的 JProfiler 得到了相同的结果。似乎 JDK 分析 API 报告了本机方法的不准确结果，至少在 OS X 下是这样。

【问题讨论】：

如果 atan 是一个内在函数，我不会感到惊讶 - 不是调用方法，而是内联注入等效的机器代码。
我在 Mac OS X 10.7（以及更早的版本）上使用 StrictMath 中的各种方法也遇到过这种情况。
那么有没有办法解决这个问题？

标签： java macos profiling native yourkit

【解决方案1】：

这可能是由于采样时间不一致造成的。因此，例如，如果一个方法使用了相当长的时间，但执行时间并不长，那么采样可能会错过它。另外，我认为垃圾收集在示例期间永远不会发生，但如果某些代码导致大量垃圾收集，它可能会大大降低速度而不会出现在示例中。

在类似的情况下，我发现运行两次非常有帮助，一次进行跟踪，一次进行采样。如果一个方法出现在两者中，它可能使用了大量的 CPU，否则它很可能只是采样过程的产物。

【讨论】：

【解决方案2】：

由于您使用的是 Mac，您可以尝试 Apple's Shark profiler（从 ADC 免费下载），它支持 Java，Apple 的性能小组已经在该工具上投入了大量时间。

正如 Nick 指出的那样，如果采样间隔与函数的执行时间足够接近，并且分析器很少检查函数实际执行的时间，则采样可能会产生误导。我不知道 YourKit 是否支持这一点，但在 Shark 中，您可以将采样间隔更改为默认 10 毫秒以外的值，看看结果是否有很大不同。还有一个单独的调用跟踪模式，它将记录每个函数的输入/返回 - 这完全避免了别名错误的可能性，但会收集大量数据和更高的开销，如果您的应用程序正在执行任何类型的实时处理，这可能很重要.

【讨论】：

【解决方案3】：

您可能想查看传递给这三个方法的参数。可能是时间花在了生成返回值或创建大量临时对象的方法上。

【讨论】：

【解决方案4】：

我发现 YourKit 大大夸大了调用子方法的成本（我假设是由于它的日志记录方法）。如果您只遵循配置文件给您的建议，您最终只会合并功能而没有真正的收益，因为 HotSpot 通常在这方面做得很好。

因此，我强烈建议也完全在分析器之外测试批次，以便更好地了解更改是否真的有益（这似乎很明显，但这会花费我一些开发时间）。

【讨论】：

【解决方案5】：

值得注意的是，如果 Java 方法足够小，则可以内联，但是本地方法在不同的规则下内联。如果一个方法是内联的，它不会出现在分析器中（当然不是 YourKit）

【讨论】：

【解决方案6】：

Profilers 可以是这样的。

This is the method I use.

每次都有效。

And this is why.

【讨论】：

想解释一下为什么这会导致与自动化此过程的采样分析器产生的结果不同的结果？
@ziggystar：一些采样分析器在挂钟（而不是 CPU）时间自动完成一半的过程，即对整个堆栈进行采样的那些。他们没有自动化的一半过程是发现您可以解决的性能问题。如果一个语句或函数的包含百分比很小，那么问题就出在其他地方，但这并不能缩小问题所在。仅仅知道一行代码、函数或“路径”是“热的”并不能告诉你太多。如果您可以完整地检查特定的代表性样本，则更具启发性。 ...
@ziggystar: ... 这导致的不同结果是，您会发现即使使用非常好的分析器也找不到的加速。当您修复这些并重复该过程时，以前的小问题现在变得更大，因为程序花费的时间更少。因此，您一一修复这些问题，复合加速可能会令人惊讶。您使用分析器获得了多少加速？如果答案超过 40%，我会感到惊讶。
超过 10 倍，使用 jvisualvm。不是一次，而是始终如一（我通常优化一种高级语言：Scala）。就在今天，我已经优化了我的一个程序，从比优化的 C++ 库慢 10 倍到不到 4 倍。我的代码已经相当优化，但 C++ 性能已经达到。关于其余的：我遇到了这里提到的与采样分析器（jvisualvm）相同的问题。而且我还进行了手动堆栈转储。他们也喜欢原生方法。我想这是 JVM 堆栈转储的问题。
@ziggystar：10 倍还不错。 Here's 43x 和 here's 730x。不同之处不在于样本的获取，而在于获取样本后如何处理它们。然后事实证明，对大量样本的需求并不是基于任何东西。统计理由在here 讨论。