JVM Promotion Fail FGC问题解决

一、现象

某系统每台机器每天都会出现一次fgc时间过长的告警。

二、分析

1.查看监控，发现每天无规律的会发生达到5-7秒的fgc。

注：该监控上的fullgc监控采用的是jmx的统计方式，所以其实是对oldgc的监控，因为除了CMS和
G1以外的垃圾回收器的old gc只能由fullgc触发，所以大部分情况下oldgc次数就是fullgc次数，
oldgc时间接近于fullgc时间。

2.查看对应fgc时间点的gc日志，发现全部都发生了promotion fail，确认是晋升失败引起过长的fgc(Old Serial gc)

从gc日志可知，可用年轻代2516544K，发生promotion fail的时候年轻代几乎没有回收对象(从2274227K到2270163K只减少了4064K)，年轻代剩余可用空间2516544K-2270163K=246381K<2270163K，年轻代空间不足，需要提前晋升到年老代2270163K-246381K=2023782K。年老代此时剩余可用空间5592448K-4276438K=1316010K，小于2023782K，年老代不足，晋升失败，触发fgc。

注：promotion fail（晋升失败）
eden区空间不足引起ygc，ygc后eden和survivor区回收不了的对象，需要复制到另外一个survivor区，
这个时候发现这个survivor区空间不足以容纳这些对象，发生提前晋升到老年代，老年代也容纳不了这些
对象，从而触发了fgc（CMS不提供fgc方案，所以使用的是串行fgc，效率可见而知。G1垃圾回收器也是如此）产生promotion fail的可能原因：
1.年轻代太小，需要调大年轻代
2.年老代太小，需要调大年老代
3.年老代空间充足，但有内存碎片，需要开启内存碎片整理

三、解决过程

分析JVM参数

-server -Xms8192m -Xmx8192m -XX:MaxMetaspaceSize=256m

可以看出，原来的JVM参数除了设置堆大小和方法区大小，其它的配置都是使用默认值，即各个分区大情况(整堆大小：8192m)：

年轻代大小：8192m*1/3=2796160K

年老代大小：8192m*2/3=5592448K

年轻代eden区大小: 2796160K*8/10 = 2236928K

年轻代survivor区大小：2796160K*2/10=559232K

可用年轻代大小：eden区+单个surviror区=2236928K+279616K=2516544K

排除是由于内存碎片而导致的promotion fail

1、默认已经开启内存碎片整理：-XX:+UseCMSCompactAtFullCollection -XX:CMSFullGCsBeforeCompaction=0

2、从名字服务/sunfire监控上看内存情况也可以知道old gc都发生在使用率达到90%，也符合-XX:CMSInitiatingOccupancyFraction默认值是90的配置。

第一次调优

考虑到业务是对App提供服务，理论上很多对象都是短生命对象，因而思路一是加大年轻代，提供更大的ygc空间，让对象尽可能在年轻代回收，避免对象晋升到老年代。

jvm参数调整

-server -Xms8192m -Xmx8192m -Xmn4g -XX:MaxMetaspaceSize=256m

加大年轻代空间到4g，有可能加快old gc频率，所以加大年轻代的前提是老年代原来的old gc频率不是很高：如下图，>2小时一次oldgc)

效果

ygc每分钟减少2~5次，但每天仍然会有1到2次的promotion fail发生。

结论

第一次调优失败。

第二次调优

分析第一次调优后的gc日志发现，发生promotion fail的时候年轻代的空间几乎没被回收，怀疑会不会有大对象瞬间堆积（从监控上观察内存使用情况，排除了内存溢出的可能）。因而希望在发生fgc的时候能知道当时内存的使用情况。

jvm参数调整:

-server -Xms8192m -Xmx8192m -Xmn4g -HeapDumpBeforeFullGC -XX:MaxMetaspaceSize=256m

在即将发生fgc之前dump内存，dump文件没指定路径则存放在当前目录。

结果：

11.17号02:27分dump出了一份fgc的内存快照：

http://xxx.xxx.cn/service/index.html#/zprofiler/heap/upload-20181117023059185-zprofiler-heap.675B.bin/overview

分析：

借助zprofile分析，确实没有可疑的内存溢出。分析类簇，发现ConcurrentSkipListMap$Node和ConcurrentHashMap$Node各占了1.2g和1.8g。继续跟踪，发现很多CacheStatState和DBStatState，这个是框架里的缓存和数据库统计对象，会在内存堆积60秒后再写入磁盘：

基于上面的分析，业务上缓存和数据库查询使用得很多（无法短时间内减少统计对象），框架也不再提供更新（无法短时间内调整统计对象的刷盘策略），所以只能继续尝试第二次JVM参数调优。

统计对象堆积可能会占用比较大的内存，但这些对象是短生命周期的，很多用完就应该回收。所以第二次参数调优仍然坚持第一次的调优方向：让对象尽可能在年轻代消亡。

这次加大了年轻代的扩容力度：

1.年轻代加大到5g

2.提高晋升年龄（ajdk默认值是6,提高到最大值15）

3.加大survivor的空间使用率（ajdk默认值是50,提高到90%）

调整后的JVM参数

-server -Xms8192m -Xmx8192m -Xmn5g -XX:MaxMetaspaceSize=256m -XX:TargetSurvivorRatio=90 -XX:MaxTenuringThreshold=15

效果

promotion fail从每天1-2次降低到0-1次，但是每次fgc停顿时间增加到了6-7秒。主要是调大的年轻代加大了old gc在重新标记阶段的扫描停顿时间。

结论

第二次调优失败。

第三次调优

在对前面两次的gc日志分析后发现，年轻代无论调多大，总会有对象在某瞬间堆积导致promotion fail，配置多大吃多大，所以加大年轻代不仅没有解决问题，反而增加了fgc时间（cms两次停顿都需要扫描年轻代）。

因此调整了调优方向：

在无法确定对象为何堆积的情况下，把fgc的时间打散，即用多次cms gc来避免fgc，减少集中停顿的时间。

需要注意的是，因为cms gc是并发gc，所以会跟用户线程抢占cpu资源。因为我们的uae容器的cpu是
8核，负载较低(1~1.5左右)，cpu使用率也在1~1.5之间。cpu不是瓶颈，CMS并发对cpu资源影响不
大。

这次调优从promotion fail的产生原因，在原来参数的基础上，得出理论值公式：eden+survivor<=old*（1-阀值），计算出阀值60，为加大减少promotion fail的可能，设置为55。

调整后的JVM参数

-XX:TargetSurvivorRatio=90 -XX:MaxTenuringThreshold=15 -XX:CMSInitiatingOccupancyFraction=55 -XX:+UseCMSInitiatingOccupancyOnly -XX:+HeapDumpBeforeFullGC

效果

灰度一台机子，两天没有发生promotion fail，也没有发生full gc，每次cms gc时间为300到500ms。灰度扩大到所有机器，在12.8凌晨第一轮压测没有发生promotion fail，也没有发生fgc。

结论

fgc从每天1~3次减少到现在每天0次,停顿时间从每次5~7s减少到现在每次300~700ms，fgc时间过长的问题基本得到解决。问题虽然解决但仍还有可优化空间。

后续可调优空间

1、升级为G1垃圾回收器

‌ 更高的内存使用率

（1）相对于CMS在多次gc后才进行内存压缩，G1在每次回收时都会进行“局部压缩”（把多个region合并为一个region）。

（2）G1垃圾回收器的eden、survivor、old区只是逻辑上的概念，物理上并没有明显的区分，一个region属于哪个分区是不确定的，这就使得G1可以通过灵活调整分区大小来达到用户设定的停顿时间。这点特别符合我们的问题场景:大部分时间对象都能在ygc时候在年轻代里消亡，只有小部分时间对象在年轻代堆积发生promotion fail。如果使用G1，大部分时间下年轻代region会占大部分，在发生对象堆积的时候，可能会动态减少年轻代region数而提高老年代region数，避免promotion fail而出现过长的fgc。

可设置的停顿时间，配置简单。
业务服务器8核cpu、8g的JVM内存，符合G1的硬件配置要求。

2、优化程序，根究对象在年轻代瞬间堆积的原因

虽然通过dump文件发现统计缓存对象存在大量堆积的情况，但从监控上看堆积的时间点没有明显的流量异常，需要进一步确认引起promotion fail的对象，才可能对症下药优化程序。