从JDK8升级到JDK11，使用G1 GC，HBase性能下降近20%。 JDK到底干了什么？
HBase从2.3.x开始正式默认的支持JDK11， HBase对于JDK 11的支持指的是HBase本身可以通过JDK11的编译、同时相关的测试用例全部通过。由于HBase依赖Hadoop和Zookeeper，而目前Hadoop和Zookeeper尚未支持JDK11，所以HBase中任然有一个jira来关注JDK11支持的问题。https://issues.apache.org/jira/browse/HBASE-22972.
G1 GC从JDK9以后就称为默认的GC，而且HBase在新的版本中也采用G1 GC.对于HBase是否可以在生成环境中使用JDK11？笔者尝试使用JDK11来运行新的HBase，严重JDK11是否比JDK8有优势。
1 环境介绍
验证的方式非常简单，搭建一个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采用JDKu222和JDK11.0.8分别进行测试，当切换JDK时，客户端和3台HBase服务器同意切换。JDK的运行参数为：
-XX:+PrintGCDetails -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:-ResizePLAB
注意：这里对禁止ResizePLAB是业务根据HBase优化资料设置。
2 测试结果：JDK11性能下降
通过PE进行测试，运行结束有TPS数据，表示性能。
在相同的硬件环境、相同的HBase，仅仅使用不同的JDK来运行。同时为了保证结果的准确性，多次运行，取平均值。测试结果如下：
从表中可以快速的计算得到吞吐量下降，运行时间增加。
结论：使用G1 GC，JDK11相对于JDK8来说性能明显下降。
3 原因分析
从JDK8到JDK11， G1 GC做了非常多的优化用于提高性能。为什么JDK11对于应用的来说更不友好？简单的总结一下从JDK8到JDK11做的一些比较大的设计变化，如下表所示：
| 优化点 |
描述 |
| IHOP启发式设置 |
IHOP用于控制并发标记的启动时机，在JDK9中引入该优化，根据应用运行的情况，计算IHOP的值，确保在内存耗尽以前启动并发标记。对于性能和运行时间理论上都是正优化，在一些的情况，例如可能会导致性能下降 |
| Full GC的并行话 |
在JDK10中将Full GC从串行实现优化为并行实现，该优化不会产生负面影响 |
| 动态线程调整 |
根据GC工作线程的负载情况，引入动态的线程数来处理任务。该优化会带来正效果，注意不是GC工作线程数目越多GC的效果越好（GC会涉及到多线程的任务窃取和同步机制，过多的线程会导致性能下降） |
| 引用集的重构 |
引用集处理优化，设置处理大小、将并行修改为并发等 |
由于从JDK8到JDK11特性变化太多，对于这样的性能下降问题，如何能快速有效的解决。我们做了如下的尝试
3.1 统一JDK8和JDK11的参数，验证效果
由于JDK11和JDK8实现变化很多，部分功能完全不同，但是这些变化的功能一般都有参数控制，一种有效的尝试：梳理JDK8和JDK11关于G1的参数，将它们设置为相同的值，比如关闭IHOP的自适应，关闭线程调整等。这里简单的给出JDk8和JDK11不同参数的比较，如下图所示：
将两者参数都设置和JDK8一样的值，重新验证测试，结果不变，JDK11性能仍然下降。
3.2 GC日志分析，确定JDK11性能下降点
对于JDK8和JDK11同时配置日志收集功能，重新测试，获得GC日志。通过GC日志分析，我们发现差异主要在G1 young gc的object copy阶段（耗时基本在这），JDK11的Young GC耗时大概200ms，JDK8Young GC耗时大概100ms，两者设置的目标停顿时间都是100ms。
JDK11中GC日志片段
JDK8中GC日志片段
我们对整个日志做了统计，有以下发现：
- 并发标记时机不同，混合回收的时机也不同；
- 单次GC中对象复制的耗时不同，JDK11明显更长；
- 总体GC次数JDK11的更多，包括了并发标记的停顿次数；
- 总体GC的耗时JDK11更多。
针对Young GC的性能劣化，我们重点关注测试了和Young GC相关的参数，例如：调整UseDynamicNumberOfGCThreads、G1UseAdaptiveIHOP 、GCTimeRatio均没有效果。
尝试使用不同的工具来进一步定位到底哪里出了问题。
3.3 JFR分析-确认日志分析结果
毕昇JDK11和JDK8都引入了JFR，JFR作为JVM中问题定位的新贵，我们也在该案例进行了尝试，关于JFR的原理和使用，参考本系列的其他文章（JFR原理介绍和使用）。
3.3.1 JDK11总体信息
JDK8中通过JFR收集信息。
3.3.2 JDK8总体信息
JFR的结论和我们前面分析的结论一致，JDK11中中断比例明显高于JDK8。
3.3.3 JDK 11中垃圾回收发生的情况
3.3.4 JDK 8中垃圾回收发生的情况
从图中可以看到在JDK11中应用消耗内存的速度更快（曲线速率更为陡峭），根据垃圾回收的原理，内存的消耗和分配相关。
3.3.5 JDK11中VM操作
3.3.6 JDK8中VM操作
通过JFR整体的分析，得到的结论和我们前面的一致，确定了Young GC可能存在问题，但是没有更多的信息。
3.4 火焰图-发现热点
为了进一步的追踪Young GC里面到底发生了什么导致对象赋值更为耗时，我们使用Async-perf进行了热点采集。关于该工具的使用参考本系列的其他文章（如何使用火焰图解决性能问题）
3.4.1 JDK11的火焰图
3.4.2 JDK 11 GC部分火焰图
3.4.3 JDK8的火焰图
3.4.4 JDK 8 GC部分火焰图
通过分析火焰图，并比较JDK 8和JDK 11的差异，可以得到：
在JDK 11中，耗时主要在：
- G1ParEvacuateFollowersClosure::do_void()
- G1RemSet::scan_rem_set
在JDK 8中，耗时主要在：
G1ParEvacuateFollowersClosure::do_void()
更一步，我们对JDK11里面新出现的scan_rem_set（）进行更进一步分析，发现该函数仅仅和引用集相关，通过修改RSet相关参数（修改G1ConcRefinementGreenZone），将RSet处理尽可能的移除Young GC的处理。火焰图中参数不再成为热点，但是JDK11仍然性能下降。
比较JDK8和JDK11中G1ParEvacuateFollowersClosure::do_void()中的不同的，出来数组处理基本没有变化，我们将JDK 11此处的代码修改和JDK8完全一样，但是性能仍然下降。
结论：虽然G1ParEvacuateFollowersClosure::do_void()是性能下降的触发点，但是此处并不是问题的根因，应该是其他的原因造成了该函数调用次数增加或者耗时增加。
3.5 逐个版本验证-最终确定问题
我们分析了所有可能的情况，仍然无法快速找到问题的根源，只能使用最笨的办法，逐个版本来验证从哪个版本开始性能下降。
在大量的验证中，对于JDK9，JDK10，以及小版本等都重新做了构建（关于JDK的构建可以参考官网），我们发现JDK9-B74和JDK9-B73有一个明显的区别。为此我们分析了JDK9-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
- B74发现有问题（desired_plab_sz可能会有相除截断问题和没有对齐），重新修改，具体见8079555: REDO - Determining the desired PLAB size adjusts to the the number of threads at the wrong place
- B115中发现B74的修改，动态调整PLAB大小后，会导致很多情况PLAB过小（大概就是不走PLAB，走了直接分配），频繁的话会导致性能大幅下降，又做了修复Net PLAB size is clipped to max PLAB size as a whole, not on a per thread basis
重新修改了代码，打印plab的大小。对比后发现desired_plab_sz大小，在性能正常的版本中该值为1024或者4096（分别是YoungPLAB和OLDPLAB），在性能下降的版本中该值为258。由此确认desired_plab_sz不正确的计算导致了性能下降。
3.6 PALB 为什么会引起性能下降？
PLAB是用于GC工作线程的并行复制内存时使用的缓存，用于减少多个并行线程在内存分配时锁竞争。PLAB的大小直接影响GC工作线程的效率。
在GC引入动态线程调整的功能时，将原来PLABSize的的大小作为多个线程的总体PLAB的大小，将PLAB重新计算到，如下面代码片段：
其中desired_plab_sz主要来自YoungPLABSize和OldPLABSIze的设置。所以这样的代码修改改变了YoungPLABSize、OldPLABSize参数的语义。
另外，在本例中，通过参数显示的禁止了ResizePLAB是触发该问题的必要条件，当打开ResizePLAB后，PLAB会根据GC工作线程晋升对象的大小和速率来逐步调整PLAB的大小。
注意，众多资料说明：禁止ResziePLAB是为了防止GC工作线程的同步，这个说法是不正确的，PLAB的调整耗时非常的小。PLAB是JVM根据GC工作线程使用内存的情况，根据数学模型来调整大小，由于模型的误差，可能导致PLAB的大小调整不一定有人工调参效果好。如果你没有对YoungPLABSize、OldPLABSize进行调优，并不建议禁止ResizePLAB。在HBase测试中，当打开ResizePLAB后JDK8和JDK11性能基本相同，也从侧面说明了该参数的使用情况。
3.7 解决方法&修复方法
由于该问题是JDK9引入，在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；代码见：https://github.com/openjdk/jdk/pull/1474。该问题在JDK 17中被修复。
同时该问题在毕昇JDK所有版本中第一时间得到解决。
当然对于没有自己JDK发行的同学，遇到这个问题，该如何解决？总不能等到JDK 17？一个临时的方法是显示的设置YoungPLABSize和OldPLABSize的值。YoungPLABSize设置为YoungPLABSize* ParallelGCThreads，其中ParallelGCThreads为GC并行线程数。例如YoungPLABSize原来为1024，ParallelGCThreads为8，在JDK9~16，将YoungPLABSize设置为8192即可。
其中参数 ParallelGCThreads的计算方法为：没有设置该参数时，当CPU个数小于等于8， ParallelGCThreads等于CPU个数，当CPU个数大于8，ParallelGCThreads等于CPU个数的5/8）.
3.8 小结
本文分享了针对JDK升级后性能下降的解决方法。对于Java开发人员如果遇到此类问题，通常可以先求助社区，但是由于社区响应较慢。自己可以先尝试：
- 对齐不同JDK版本的参数，确保参数相同，看是否可以快速重现
- 分析GC日志，确定是否由GC引起。如果是建议将所有的参数重新验证，包括移除原来的参数。本例中一个最大的失误是，在分析过程中将原来业务提供的参数ResizePLAB移除重新测试，浪费了很多时间。如果执行该步骤后，定位问题可能可以解决很多时间；
- 使用一些工具，比如JFR、NMT、火焰图等。本例中尝试使用这些工具，虽然无果，但基本上确认了问题点。
- 最后的最后，还是没有结果，请找毕昇JDK社区吧
- 点赞
- 收藏
- 关注作者
评论（0）