Perf & FlameGraph

Jun 19, 2023 min read

本文在飞书文档完成,所以导出为md格式有一些排版问题,另附PDF文件,建议阅读PDF文件。

    / [pdf]

运行环境

主要通过一台 Ubuntu 20.04 的机器运行,具体运行环境如下表所示。

表 1 运行环境

项目 内容
系统 Ubuntu 20.04
Kernel 5.15.0-74-generic
CPU Intel I5-12400F
内存 32G

SPECjvm2008

分别在 Ubuntu 和 Windows11 系统下进行了全量测试。因为 JDK 1.8 在运行 startup.compiler.sunflow 用例时阻塞,添加"-nowarn"后重新编译会导致 checksum 校验无法通过,所以结果是 non compliant。如果使用 JDK 1.7 不会有这种问题。

图 1 Ubuntu20.04 Oracle JDK1.8u371 644.61ops/m

图 2 Ubuntu20.04 Oracle JDK1.7u80 582.39ops/m

在 Ubuntu20.04 系统下,Oracle JDK1.8u371 的分数为 644.61ops/m,Oracle JDK1.7u80 的分数为 582.39 ops/m。其中 JDK1.8 和 JDK1.7 在 crypto 和 derby 上差距比较明显,其中 crypto 差距最明显的 workload 是 crypto.rsa,二者的分数分别为 5390.14 和 1355.95,后面我尝试分析了性能差距的来源,具体分析见第三章的实践。

Compress 用例下不同 JDK 对比

这里测试了几个主流的 JDK 在 Compress 用例下进行三轮测试的表现,数据如下:

表 2 JDK 在 compress 用例下的对比

JDK Round1 Round2 Round3 Mean Std
Oracle JDK 8-371 697.6 703.8 700.57 700.66 3.10
Open JDK 8-372 707.22 707.2 707.72 707.38 0.29
TecentKona JDK 8-322 706.73 706.63 708.19 707.18 0.87
BiSheng JDK 8-372 716.66 713.3 705.17 711.71 5.91
Alibaba Dragonwell JDK8-372 713.46 708.49 708.95 710.3 2.75

可以看到,主流的 JDK 在 Compress 用例下表现比较接近,其中 Oracle JDK 8-371 平均得分最低,为 700.66。BiSheng JDK8-372 最高,平均得分为 711.71。由于仅进行了三轮测试,并且得分非常接近,我认为根据这些数据得到的排名不是很可靠,后续可以考虑更完善的对比实验。

Perf & Flame Graph

分别通过 Perf & Perf-map-agent & Flame Graph 和 async- profiler 生成了火焰图,并对比了这两种方式生成火焰图对性能区别,由于时间原因只测试了一轮,Oracle JDK 8 取表 2 里它的平均值。

表 3 不同火焰图生成方法对性能的影响

JDK ops/m 下降
Oracle JDK 8-371 700.6567
+Perf-map-agent 651.64 下降约 7%
+Perf-map-agen&+PreserveFramePointer 637.19 下降约 9%
+async-profiler 698.92 下降约 0.3%

可以看到,如果使用 Perf,对性能的影响是很高的,通过 sar -u 命令,在使用 Perf 采样 SPECjvm 时,%user 为 91.7%,%system 为 7.81%,作为对比,与未使用 perf 时运行 compress 用例的 %user 为 99.09%,%system 为 0.17%。使用 Perf 采样 SPECjvm 时 CPU 占用比例如下:

图 3 SPECjvm 时 CPU 占用比例

如果使用 Perf-map-agen 时不设置 XX:+PreserveFramePointer 保留帧指针的话,火焰图只会显示栈顶的函数,如图 5 所示,但开启后会额外带来性能损失,同时开启 Perf-map-agen&PreserveFramePointer 的得分下降了 9%。我这里缺失了单独开启 PreserveFramePointer 的性能实验,不过根据 Netflix 的报告(https://netflixtechblog.com/java-in-flames-e763b3d32166),性能损耗在 0 到 3% 左右。

async-profiler 对性能的影响很小,应该和它使用的 AsyncGetCallTrace 有关,需要后续探索。生成的火焰图如下:

图 6 使用 perf map agent 并开启 PreserveFramePointer

图 7 使用 async-profiler

性能分析尝试

在第 2 章提到 Orcale JDK1.8 和 JDK1.7 在 crypto 和 derby 上差距比较明显,其中 crypto 差距最明显的 workload 是 crypto.rsa,二者的分数分别为 5390.14 和 1355.95。这里尝试探索二者性能差距的来源。

为了分析主要的性能区别,我通过 async-profiler 分别生成了 JDK1.8 和 JDK1.7 运行 crypto.rsa 的火焰图:

图 8 Orcale JDK1.8 运行 crypto.rsa 的火焰图

图 9 Orcale JDK1.7 运行 crypto.rsa 的火焰图

可以看到, BigInteger.modPow 的运行时间占比从 jdk1.7 中的 90% 下降到 JDK 1.8 中的 80%,并且二者的 stack 不太一致,因此我猜想性能差距的原因是不同 JDK 的 BigInteger.modPow 的性能不一样。为了验证我的猜想,我利用 JMH 仿照 RSA 的 m、e、c 使用 modPow 进行了实验,benchmark mode 使用 Throughput,其他均使用默认参数,结果如下:

表 4 BigInteger.modPow 性能对比

版本 Score(ops/s) Errors
1.8 2904.053 4.780
1.7 741.030 19.919

根据火焰图上出现的 montgomery_multiply,我们可以在 https://bugs.openjdk.org/browse/JDK-8153189https://bugs.openjdk.org/browse/JDK-8081778 找到相关的改进。

图 10 JDK release note 8130150

图 11 JDK release note 8081778

看起来是添加了一些关于 montgomery multiply 的 intrinsic 导致 JDK1.8 的 modPow 性能远超 JDK1.7。如果我们关闭 JDK1.8 的这些 intrinsic,那么 JDK1.7 和 JDK1.8 的性能会比较接近。

表 5 关闭相关 intrinsic 前后性能对比

项目 版本 得分
JMH BigInteger.modPow Oracle JDK1.8u371 2904.053
1.8u371 关闭 intrinsic 853.419
Oracle JDK 1.7u80 741.030
SPECjvm crypto.rsa Oracle JDK 1.8u371 5390.14
1.8u371 关闭 intrinsic 1493.99
Oracle JDK 1.7u80 1355.95

存在的问题

  1. 使用 perf-map-agent 生成火焰图时,相同的脚本有时图像上显示 unknown,有时正常显示为图 6 的状态。我的脚本如下:
set -m
export setting PERF_RECORD_SECONDS=360
java -XX:+PreserveFramePointer -jar SPECjvm2008.jar  -ikv compress &
spec_pid=$!
echo $spec_pid
perf-java-flames $spec_pid  -F 99 -a -g -p $spec_pid &
wait

生成的图像由两种情况,一种是下图,一种是图 6。

图 12 perf-map-agent 异常情况

  1. 另外尝试使用 GCViewer 观察 GC 日志:

图 3 GCViewer 分析

但目前不知道应该注意哪些指标,另外 arthas 看起来是一个更全面的工具,后面可以尝试使用。