vlambda博客
学习文章列表

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

编者按:笔者在 HBase 业务场景中尝试将 JDK 从 8 升级到 11,使用 G1 GC 作为垃圾回收器,但是性能下降 20%。到底是什么导致了性能衰退?又该如何定位解决?本文介绍如果通过使用 JFR、火焰图等工具确定问题,最后通过版本逐一验证找到了引起性能问题的代码。在毕昇 JDK 中率先修复问题最后将修复推送到上游社区中。希望通过本文的介绍让读者了解到如何解决大版本升级中遇到的性能问题;同时也提醒 Java 开发者要正确地使用参数(使用前要理解参数的含义)。

HBase技术社区
HBase技术交流社区,共同探讨HBase技术
166篇原创内容
Official Account

HBase 从 2.3.x 开始正式默认的支持 JDK 11,HBase 对于 JDK 11 的支持指的是 HBase 本身可以通过 JDK 11 的编译、同时相关的测试用例全部通过。由于 HBase 依赖 Hadoop 和 Zookeeper,而目前最新的 Hadoop 和 Zookeeper 尚未支持 JDK 11,所以 HBase 中仍然有一个 jira 来关注 JDK 11 支持的问题,具体参考:https://issues.apache.org/jira/browse/HBASE-22972。

G1 GC 从 JDK 9 以后就成为默认的 GC,而且 HBase 在新的版本中也采用 G1 GC,对于 HBase 是否可以在生产环境中使用 JDK 11?笔者尝试使用 JDK 11 来运行新的 HBase,验证 JDK 11 是否比 JDK 8 有优势。

环境介绍

验证的方式非常简单,搭建一个 3 节点的 HBase 集群,安装 HBase,采用的版本为 2.3.2,关于 HBase 环境搭建可以参考官网。

另外为了验证,使用一个额外的客户端机器,通过 HBase 自带的 PerformanceEvaluation 工具(简称 PE)来验证 HBase 读、写性能。PE 支持随机的读、写、扫描,顺序读、写、扫描等。

例如一个简单的随机写命令如下:

hbase org.apache.hadoop.hbase.PerformanceEvaluation --rows=10000 --valueSize=8000 randomWrite 5

该命令的含义是:创建 5 个客户端,并且执行持续的写入测试。每个客户端每次写入 8000 字节,共写入 10000 行。

PE 使用起来非常简单,是 HBase 压测中非常流行的工具,关于 PE 更多的用法可以参考相关手册。

本次测试为了验证读写性能,采用如下配置:

org.apache.hadoop.hbase.PerformanceEvaluation --writeToWAL=true --nomapred --size=256 --table=Test1 --inmemoryCompaction=BASIC --presplit=50 --compress=SNAPPY sequentialWrite 120

JDK 采用 JDK 8u222 和 JDK 11.0.8 分别进行测试,当切换 JDK 时,客户端和 3 台 HBase 服务器统一切换。JDK 的运行参数为:

-XX:+PrintGCDetails -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:-ResizePLAB

注意:这里禁止 ResizePLAB 是业务根据 HBase 优化资料设置。

测试结果:JDK 11 性能下降

通过 PE 进行测试,运行结束有 TPS 数据,表示性能。

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

在相同的硬件环境、相同的 HBase,仅仅使用不同的 JDK 来运行。同时为了保证结果的准确性,多次运行,取平均值。测试结果如下:

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

从表中可以快速地计算得到吞吐量下降,运行时间增加。

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

结论:使用 G1 GC,JDK 11 相对于 JDK 8 来说性能明显下降。

原因分析

从 JDK 8 到 JDK 11, G1 GC 做了非常多的优化用于提高性能。为什么 JDK 11 对于应用者来说更不友好?简单的总结一下从 JDK 8 到 JDK 11 做的一些比较大的设计变化,如下表所示:

优化点 描述
IHOP 启发式设置 IHOP 用于控制并发标记的启动时机,在 JDK 9 中引入该优化,根据应用运行的情况,计算 IHOP 的值,确保在内存耗尽之前启动并发标记。对于性能和运行时间理论上都是正优化,特殊情况下可能会导致性能下降
Full GC 的并行话 在 JDK10 中将 Full GC 从串行实现优化为并行实现,该优化不会产生负面影响
动态线程调整 根据 GC 工作线程的负载情况,引入动态的线程数来处理任务。该优化会带来正效果,注意不是 GC 工作线程数目越多 GC 的效果越好(GC 会涉及到多线程的任务窃取和同步机制,过多的线程会导致性能下降)
引用集的重构 引用集处理优化,设置处理大小、将并行修改为并发等

统一 JDK 8 和 JDK 11 的参数,验证效果

由于 JDK 11 和 JDK 8 实现变化很多,部分功能完全不同,但是这些变化的功能一般都有参数控制,一种有效的尝试:梳理 JDK 8 和 JDK 11 关于 G1 的参数,将它们设置为相同的值,比如关闭 IHOP 的自适应,关闭线程调整等。这里简单的给出 JDK 8 和 JDK 11 不同参数的比较,如下图所示:

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

将两者参数都设置为和 JDK 8 一样的值,重新验证测试,结果不变,JDK 11 性能仍然下降。

GC 日志分析,确定 JDK 11 性能下降点

对于 JDK 8 和 JDK 11 同时配置日志收集功能,重新测试,获得 GC 日志。通过 GC 日志分析,我们发现差异主要在 G1 young gc 的 object copy 阶段(耗时基本在这),JDK 11 的 Young GC 耗时大概 200ms,JDK 8 的 Young GC 耗时大概 100ms,两者设置的目标停顿时间都是 100ms。

JDK 11 中 GC 日志片段:

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JDK 8 中 GC 日志片段:

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

我们对整个日志做了统计,有以下发现:

  • 并发标记时机不同,混合回收的时机也不同;

  • 单次 GC 中对象复制的耗时不同,JDK 11 明显更长;

  • 总体 GC 次数 JDK 11 的更多,包括了并发标记的停顿次数;

  • 总体 GC 的耗时 JDK 11 更多。

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

针对 Young GC 的性能劣化,我们重点关注测试了和 Young GC 相关的参数,例如:调整 UseDynamicNumberOfGCThreadsG1UseAdaptiveIHOP 、GCTimeRatio 均没有效果。

下面我们尝试使用不同的工具来进一步定位到底哪里出了问题。

JFR 分析-确认日志分析结果

毕昇 JDK 11 和毕昇 JDK 8 都引入了 JFR,JFR 作为 JVM 中问题定位的新贵,我们也在该案例进行了尝试,关于 JFR 的原理和使用,参考本系列的技术文章:

JDK 11 总体信息

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JDK 8 中通过 JFR 收集信息。

JDK 8 总体信息

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JFR 的结论和我们前面分析的结论一致,JDK 11 中中断比例明显高于 JDK 8。

JDK 11 中垃圾回收发生的情况

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JDK 8 中垃圾回收发生的情况

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

从图中可以看到在 JDK 11 中应用消耗内存的速度更快(曲线速率更为陡峭),根据垃圾回收的原理,内存的消耗和分配相关。

JDK 11 中 VM 操作

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JDK 8 中 VM 操作

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

通过 JFR 整体的分析,得到的结论和我们前面的一致,确定了 Young GC 可能存在问题,但是没有更多的信息。

火焰图-发现热点

为了进一步的追踪 Young GC 里面到底发生了什么导致对象赋值更为耗时,我们使用 Async-perf 进行了热点采集。关于火焰图的使用参考本系列的技术文章:

JDK 11 的火焰图

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JDK 11 GC 部分火焰图

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

图片 JDK 8 的火焰图

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

JDK 8 GC 部分火焰图

JDK 从8升级到11,使用 G1 GC,HBase 性能下降近20%。JDK 到底干了什么?

通过分析火焰图,并比较 JDK 8 和 JDK 11 的差异,可以得到:

在 JDK 11 中,耗时主要在:

  1. G1ParEvacuateFollowersClosure::do_void()
  2. G1RemSet::scan_rem_set

在 JDK 8 中,耗时主要在:

  1. G1ParEvacuateFollowersClosure::do_void()

更一步,我们对 JDK 11 里面新出现的 scan_rem_set() 进行更进一步分析,发现该函数仅仅和引用集相关,通过修改 RSet 相关参数(修改 G1ConcRefinementGreenZone ),将 RSet的处理尽可能地从Young GC的操作中移除。火焰图中参数不再成为热点,但是 JDK 11 仍然性能下降。

比较 JDK 8 和 JDK 11 中 G1ParEvacuateFollowersClosure::do_void() 中的不同,除了数组处理外其他的基本没有变化,我们将 JDK 11 此处的代码修改和 JDK 8 完全一样,但是性能仍然下降。

结论:虽然 G1ParEvacuateFollowersClosure::do_void() 是性能下降的触发点,但是此处并不是问题的根因,应该是其他的原因造成了该函数调用次数增加或者耗时增加。

逐个版本验证-最终确定问题

我们分析了所有可能的情况,仍然无法快速找到问题的根源,只能使用最笨的办法,逐个版本来验证从哪个版本开始性能下降。

在大量的验证中,对于 JDK 9、JDK 10,以及小版本等都重新做了构建(关于 JDK 的构建可以参考官网),我们发现 JDK 9-B74 和 JDK 9-B73 有一个明显的区别。为此我们分析了 JDK 9-B73 合入的代码。发现该代码和 PLAB 的设置相关,为此梳理了所有 PLAB 相关的变动:

  • B66 版本为了解决  PLAB size 获取不对的问题(根据 GC 线程数量动态调整,但是开启  UseDynamicNumberOfGCThreads 后该值有问题,默认是关闭)修复了 bug。具体见 jira: Determining the desired PLAB size adjusts to the the number of threads at the wrong place [2]
  • B74 发现有问题( desired_plab_sz 可能会有相除截断问题和没有对齐的问题),重新修改,具体见  8079555: REDO - Determining the desired PLAB size adjusts to the the number of threads at the wrong place [3]
  • B115 中发现 B74 的修改,动态调整  PLAB大小后,会导致很多情况  PLAB过小(大概就是不走  PLAB,走了直接分配),频繁的话会导致性能大幅下降,又做了修复  Net PLAB size is clipped to max PLAB size as a whole, not on a per thread basis [4]

重新修改了代码,打印 PLAB 的大小。对比后发现 desired_plab_sz 大小,在性能正常的版本中该值为 1024 或者 4096(分别是 YoungPLAB 和 OLDPLAB),在性能下降的版本中该值为 258。由此确认 desired_plab_sz 不正确的计算导致了性能下降。

PALB 为什么会引起性能下降?

PLAB 是 GC 工作线程在并行复制内存时使用的缓存,用于减少多个并行线程在内存分配时的锁竞争。PLAB 的大小直接影响 GC 工作线程的效率。

在 GC 引入动态线程调整的功能时,将原来 PLABSize 的大小作为多个线程的总体 PLAB 的大小,将 PLAB 重新计算,如下面代码片段:

其中 desired_plab_sz 主要来自 YoungPLABSize 和 OldPLABSIze 的设置。所以这样的代码修改改变了 YoungPLABSizeOldPLABSize 参数的语义。

另外,在本例中,通过参数显式地禁止了 ResizePLAB 是触发该问题的必要条件,当打开 ResizePLAB 后,PLAB 会根据 GC 工作线程晋升对象的大小和速率来逐步调整 PLAB 的大小。

注意,众多资料说明:禁止 ResziePLAB 是为了防止 GC 工作线程的同步,这个说法是不正确的,PLAB 的调整耗时非常的小。PLAB 是 JVM 根据 GC 工作线程使用内存的情况,根据数学模型来调整大小,由于模型的误差,可能导致 PLAB 的大小调整不一定有人工调参效果好。如果你没有对 YoungPLABSizeOldPLABSize 进行调优,并不建议禁止 ResizePLAB。在 HBase 测试中,当打开 ResizePLAB 后 JDK 8 和 JDK 11 性能基本相同,也从侧面说明了该参数的使用情况。

解决方法&修复方法

由于该问题是 JDK 9 引入,在 JDK 9, JDK 10, JDK 11, JDK 12, JDK 13, JDK 14, JDK 15, JDK 16 都会存在性能下降的问题。

我们对该问题进行了修正,并提交到社区,具体见 Jira:https://bugs.openjdk.java.net/browse/JDK-8257145[5];代码见:https://github.com/openjdk/jdk/pull/1474[6];该问题在 JDK 17 中被修复。

同时该问题在毕昇 JDK 所有版本中第一时间得到解决。

当然对于短时间内无法切换 JDK 的同学,遇到这个问题,该如何解决?难道要等到 JDK 17?一个临时的方法是显式地设置 YoungPLABSize 和 OldPLABSize 的值。YoungPLABSize 设置为 YoungPLABSize* ParallelGCThreads,其中 ParallelGCThreads 为 GC 并行线程数。例如 YoungPLABSize 原来为 1024,ParallelGCThreads 为 8,在 JDK 9~16,将 YoungPLABSize 设置为 8192 即可。

其中参数 ParallelGCThreads 的计算方法为:没有设置该参数时,当 CPU 个数小于等于 8, ParallelGCThreads 等于 CPU 个数,当 CPU 个数大于 8,ParallelGCThreads 等于 CPU 个数的 5/8)。

小结

本文分享了针对 JDK 升级后性能下降的解决方法。Java 开发人员如果遇到此类问题,可以按照下面的步骤尝试自行解决:

  1. 对齐不同 JDK 版本的参数,确保参数相同,看是否可以快速重现;
  2. 分析 GC 日志,确定是否由 GC 引起。如果是,建议将所有的参数重新验证,包括移除原来的参数。本例中一个最大的失误是,在分析过程中没有将原来业务提供的参数 ResizePLAB 移除重新测试,浪费了很多时间。如果执行该步骤后,定位问题可能可以节约很多时间;
  3. 使用一些工具,比如 JFR、NMT、火焰图等。本例中尝试使用这些工具,虽然无果,但基本上确认了问题点;
  4. 最后的最后,如果还是没有解决,请联系毕昇 JDK 社区(点击原文进入社区)。毕昇 JDK 社区每双周周二举行技术例会,同时有一个技术交流群讨论 GCC、LLVM 和 JDK 等相关编译技术。
HBase技术社区
HBase技术交流社区,共同探讨HBase技术
166篇原创内容
Official Account

参考资料

[1]

使用 perf 解决 JDK8 小版本升级后性能下降的问题: https://mp.weixin.qq.com/s/aiuaB_VFw3A2iIexeizENA

[2]

Determining the desired PLAB size adjusts to the the number of threads at the wrong place: https://bugs.openjdk.java.net/browse/JDK-8073204

[3]

8079555: REDO - Determining the desired PLAB size adjusts to the the number of threads at the wrong place: https://bugs.openjdk.java.net/browse/JDK-8079555

[4]

Net PLAB size is clipped to max PLAB size as a whole, not on a per thread basis: https://bugs.openjdk.java.net/browse/JDK-8150952