jvm参数调优实战
saber599

背景

线上有个用于对接第三方电商平台接口的duubo服务,公司内部系统需要调用第三方平台接口时不用去关心平台接口,只需要调用该服务接口即可。该服务上线后一直没有关注其gc情况,最近得空,看下是否有优化空间。

现状

在启动参数上加上打印gc日志参数,使用gceasy进行gc日志分析。

1
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

堆内存gc曲线图如下:
image

图1-1

image

图1-2

通过上面两张图可以看出该服务进行FullGc次数较多,并且在进行FullGc前,老年代急剧上升,这肯定是需要进行优化的。

该服务有四个节点,起始jvm参数如下:

1
-Xms4096m -Xmx4096m -Xmn1024m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:-OmitStackTraceInFastThrow

为什么老年代急剧上升

晋升老年代方式的方式有:

  1. 大对象直接进入老年代
  2. 长期存活的对象进入老年代
  3. 动态对象年龄判定
  4. 空间分配担保

由于jdk8默认收集器Parallel Scavenge不会出现大对象直接分配到老年代情况故而从下面两种情况分析;在默认参数下,长期存活的对象需要进入老年代需要经历15次MinorGc,在没有长时间驻留线程下,不会出现经历15次MinorGc后大量年轻代对象进入到老年代;故而初步判定老年代急剧上升的原因可能有两种:

  1. 在大量调用下,又由于Survivor区较小,在动态对象年龄判定时,很容易满足相同年龄对象内存和大于Survivor区内存一半,提前晋升老年代
  2. 在大量调用下,又由于Survivor区较小,Eden区早早的被充满进行MinorGc,但由于存活对象Survivor区放不下,提前晋升老年代

调整

根据初步分析原因可两方面进行参数调整,增加新生代内存 or 增加Survivor区内存

由于该服务有四个节点,在负载均衡的前提下,可大致认为四个节点环境相同,对四个节点的参数进行不同的调整,进行比较。

节点A:原始配置

1
-Xms4096m -Xmx4096m -Xmn1024m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

节点B:调整新生代内存为1.5G

1
-Xms4096m -Xmx4096m -Xmn1536m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

节点C:调整SurvivorRatio为6

1
-Xms4096m -Xmx4096m -Xmn1024m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=6 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

节点D:调整新生代内存为1.5G & 调整SurvivorRatio为6

1
-Xms4096m -Xmx4096m -Xmn1536m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=6 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

结果分析

四个节点运行25h后GC相关图表

GC Pause Statistics
\YoungSurvivor总次数总时长平均时长最小时长最大时长
节点A1 gb102.4 mb18853 min 26 sec 831 ms110 ms20.0 ms2 sec 130 ms
节点B1.5 gb153.6 mb13352 min 37 sec 850 ms118 ms20.0 ms1 sec 420 ms
节点C1 gb204.8 mb20293 min 6 sec 250 ms91.8 ms10.0 ms2 sec 200 ms
节点D1.5 gb307.2 mb14372 min 37 sec 850 ms110 ms20.0 ms290 ms
Minor GC stats
\YoungSurvivor总次数总时长平均时长最小时长最大时长
节点A1 gb102.4 mb18703 min 8 sec 870 ms101 ms20.0 ms230 ms
节点B1.5 gb153.6 mb13302 min 34 sec 680 ms116 ms20.0 ms250 ms
节点C1 gb204.8 mb20233 min 100 ms89.0 ms10.0 ms220 ms
节点D1.5 gb307.2 mb14342 min 37 sec 380 ms110 ms20.0 ms290 ms
Full GC stats
\YoungSurvivor总次数总时长平均时长最小时长最大时长
节点A1 gb102.4 mb1517 sec 960 ms1 sec 197 ms100 ms2 sec 130 ms
节点B1.5 gb153.6 mb53 sec 170 ms634 ms70.0 ms1 sec 420 ms
节点C1 gb204.8 mb66 sec 150 ms1 sec 25 ms70.0 ms2 sec 200 ms
节点D1.5 gb307.2 mb3470 ms157 ms90.0 ms260 ms

堆内存GC前数据:

image

图A1

image

图B1

image

图C1

image

图D1

老年代晋升数据:

image

图A2

image

图B2

image

图C2

image

图D2

从图B2及图C2中可以看到在正常情况下,晋升老年代的数量是非常小的,在7日下午13:43-14:05期间,老年代迅速增长(图B1,图C1)中也可以看出,其原因确实是这段时间产生了大量调用,通过线上日志也可以看出
image
image

从上述图表可以看出:

  1. 新生代调整为1.5G或调整SurvivorRatio为6都能满足服务日常运行,一旦出现大量调用则还是会发生老年代迅速增长情况,但是比原始配置好得多。
  2. 从图D2中可以看出,在Survivor区大小为307.2 Mb左右能避免老年代迅速增长
  3. 单独看MinorGc,新生代调整1.5g后虽然平均gc时长增加了一点,但是gc次数及gc总时长减少了不少
  4. 单独看MinorGc,新生代同为1.5G下,SurvivorRatio为6时,虽然gc次数及gc总时长多了那么一点点,但是除了启动应用是进行了3次FullGc,后面都没有出现过FullGc,即使大量调用是晋升老年代也很平滑

再次调整

从上述结论看出,新生代增加到1.5G对有不少的提升。

在新生代都加到1.5G前提下,进一步减少动态对象年龄判定晋升老年代数量,将Survivor区使用率调整至307.2 Mb/2=153.6Mb左右(TargetSurvivorRatio默认为50,可用jinfo -flag 查看)

节点A:原始配置

1
-Xms4096m -Xmx4096m -Xmn1024m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

节点B:调整TargetSurvivorRatio为80

1
-Xms4096m -Xmx4096m -Xmn1536m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:TargetSurvivorRatio=80 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

节点C:调整为自适应调节

1
-Xms4096m -Xmx4096m -Xmn1536m -XX:+UseAdaptiveSizePolicy  -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log

节点D:调整新生代内存为2G & TargetSurvivorRatio为80

1
-Xms4096m -Xmx4096m -Xmn2048m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8  -XX:TargetSurvivorRatio=80 -XX:-OmitStackTraceInFastThrow -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log