正文
已知当前 JVM 核心参数如下:
-Xms12g
-Xmx12g
-XX:MetaspaceSize=512m
-XX:MaxMetaspaceSize=512m
-XX:+UseG1GC
-XX:G1HeapRegionSize=16M
-XX:MaxGCPauseMillis=100
-XX:InitiatingHeapOccupancyPercent=45
-XX:+HeapDumpOnOutOfMemoryError
-XX:MaxDirectMemorySize=1g
通过集团
ATP
工具对原始 GC 日志进行可视化分析,下图中标出了各 GC 事件的时间点和变化曲线:
从图中可以分析出如下信息:
① 蓝色圆点:一个点代表一次 YGC,横轴上堆满了密密麻麻的蓝点,说明 YGC 发生非常频繁且耗时短,毫秒级即可完成清理,这是理想中的情况。符合预期
② 粉色折线:代表堆内存占用量的变化情况,可以看到整体呈锯齿形,不断快速上升和下降。由于系统流量较大且请求执行过程会不断产生一些朝生夕灭的临时对象,因此可看到粉色折线快速上升。当 Eden 区不足时触发 YGC 清理,内存释放完成即可看到粉色折线下降到低点。符合预期
③ 异常蓝点:远离横轴说明耗时久,它们就是刚刚在日志中手动找到的长耗时 YGC 记录。
需重点关注
④ 紫色折线:代表老年代堆内存占用量的变化情况。相比之下老年代占用率上涨缓慢,因为大多数临时对象都在年轻代被清理掉了,不会进入老年代。然而观察发现每次长耗时 YGC 蓝点附近,都会伴随着紫色折线阶梯式上升。
需重点关注
其次,还可发现长耗时 YGC 往往是成对出现的,有如下规律:成对出现、时间接近、耗时都长、第一次晋升量少、第二次晋升量多,如下图所示:
综上,整合目前所有已知线索:系统在每次切换索引时,都会超时抖动,且在抖动时间点会发现连续的两次长耗时 YGC(第二次 YGC 晋升量大)。
经分析以上现象符合预期,详细过程推演还原如下:
-
阶段一:系统创建新索引,相关对象默认被分配至 Eden 区;
-
阶段二:Eden 区空间不足,触发
第一次
YGC,此时新索引被
复制
(Object Copy)到 Survivor 区,
耗时久
;
-
阶段三:新索引构造完成,并被 GcRoot 引用上,旧索引与 GcRoot 引用被断开;
-
阶段四:系统持续处理外部请求,Eden 区空间再次不足,触发
第二次
YGC,此时旧索引被清理。新索引又被
复制
(Object Copy)到 Old 区(
晋升
),
耗时久;
-
阶段五:后续即使外部流量再次把 Eden 区打满,YGC 也能毫秒级快速完成。因为只需快速清理临时对象即可,新索引已稳定在老年代不会再被腾挪复制;
至此,问题原因已非常清晰:每次新生成的索引会随着 YGC 连续复制多次,复制过程暂停久导致系统抖动。因此可考虑基于如下一些思路来针对性优化本问题,后文会逐个详细解释:
4.3.1 让索引尽早晋升到老年代
通常情况下,一个对象最初会被分配在 Eden 区,第一次 YGC 后进入 Survivor 区。此后每次 YGC 对象会在 S0 和 S1 之间反复腾挪,且每次腾挪后对象 age+1,当 age 大于默认阈值时会晋升到 Old 区。因此对象在堆内存中的流转路径是:Eden => S0 => S1 => S0 => S1 => ... => Old
由于本例中索引对象复制开销太大,因此可考虑让索引尽早晋升到老年代,避免在年轻代反复腾挪影响系统稳定性。有如下 JVM 参数可以达到此目的:
MaxTenuringThreshold
参数作用:表示对象在晋升到老年代之前,在年轻代中
最多
能够承受的
GC 周期次数
然而,结合 4.2 节实际 GC 日志截图可知,G1GC 对大对象做了动态优化——直接晋升(Direct Tenuring),并没有让索引在 Survivor 内反复腾挪。索引实际流转路径是:Eden => S0 => Old,总共只涉及 2 次复制而非默认值 15 次。此时相当于已经默认设置了 MaxTenuringThreshold=1,流程如下: