Java GC日志分析 - GC暂停时间长

用户诉求

某日接到业务同学的反馈如下：

1. 业务运行过程中经常出现超长的暂停时间，导致健康检查失败，引发问题

2. 应用本身是做离线数据处理，对时延要求不是很高，能保证大部分暂停在1200毫秒以下不要出现超长的暂停即可，更加看重应用的吞吐

3. 应用当前使用的是CMS GC，用户希望顺应技术发展趋势，升级到G1 GC，并一并解决上述问题

GC日志分析

首先看一下原本使用CMS时问题有多严重，文件上传后先调整一下分析配置：

看问题诊断，发现有很多Full GC， Final Remark和Young GC的暂停时间都会超过1200ms。

再看一下暂停视图，发现有时超时非常多。

用户修改了JVM启动参数，从CMS GC升级到G1 GC，运行了一段时间后重新上传GC日志进行分析，看问题诊断，暂停信息和GC阶段三个部分：

发现升级到G1 GC后可以看到应用的暂停时间基本满足要求了，但是由于G1默认会试图把应用暂停尽量控制在200ms以下，而当前应用的暂停整体偏长，导致G1试图把年轻代压缩得特别小来控制暂停时间，导致GC变得较为频繁，引起应用整体的吞吐下降（应用吞吐主要看的是”GC暂停时间占比“指标，从2.38%升到了3.87%）。

于是为了降低Young GC的频率增大年轻代大小，应用按照建议增加了以下JVM参数进行调优：

-XX:MaxGCPauseMillis=400 -XX:+UnlockExperimentalVMOptions -XX:G1NewSizePercent=40

运行一段时间后，发现虽然能解决GC频繁的问题，但是由于年轻代大小的最小值被设的太高，影响了G1 GC自动调节能力，导致了新的Full GC和To-space Exhausted，引起超长暂停。

于是再次进行JVM参数调优：

-XX:G1NewSizePercent=20 -XX:-XX:InitiatingHeapOccupancyPercent=40

新的参数运行一段时间后没有再发现新的问题，至此用户G1 GC升级完成。用户在Java GC日志分析工具的辅助下，通过JVM参数调优，在保持应用吞吐影响不大的情况下解决了时延问题，整体效果满意。