问题描述:
应用系统偶发出现内部耗时超过2-3秒的情况,检查日志发现,整个应用服务器的接入和接出日志都没有日志输出,类同"stop the world"。
问题分析:1、通过对应用日志统计的慢交易和JVM触发Full GC的时间点分析对比,发现的时间保持一致,JVM分析情况如下。
1)JVM 老年代垃圾回收机制为UseParallelOldGC,由于GC时STW机制会暂停所有业务线程,目前平台Full GC暂停时间1-3秒左右,在Full GC同时间点发生交易内部耗时长问题;
2)在交易高峰时段(9-12,15-17点)发生Full GC频率较高,当老年代达到2.8G时会触发Full GC,约间隔30分钟发生一次Full GC,其他时间段间隔一小时执行一次Full GC;
新生代垃圾回收(Young GC)完剩余的对象普遍在50M以上,新生代配置小(JVM内存是4G,老年代占用2.8G,新生代占用1.2G),以及FROM和TO区内存大小为自适应的问题(FROM和TO区内存为48M),导致大对象和生命周比较长的对象得不到充分的回收(未达到回收次数,默认15),导致对象直接进入老年代;
Full GC发生的时间点
2021年 11月 18日 星期四 10:16:54 CST
2021年 11月 18日 星期四 10:16:55 CST
110177 [Full GC 2803627K->412350K(4184448K), 1.7594870 secs]
2021年 11月 18日 星期四 10:16:56 CST
2021年 11月 18日 星期四 10:16:57 CST
2021年 11月 18日 星期四 14:27:34 CST
2021年 11月 18日 星期四 14:27:35 CST
120023 [Full GC 2803464K->372502K(4183168K), 1.8235800 secs]
2021年 11月 18日 星期四 14:27:36 CST
2021年 11月 18日 星期四 14:27:37 CST
2021年 11月 18日 星期四 18:02:42 CST
2021年 11月 18日 星期四 18:02:43 CST
129131 [Full GC 2565659K->372189K(4182528K), 2.4959090 secs]
2021年 11月 18日 星期四 18:02:44 CST
2021年 11月 18日 星期四 18:02:45 CST
2021年 11月 18日 星期四 13:34:12 CST
2021年 11月 18日 星期四 13:34:14 CST
118042 [Full GC 2801430K->350893K(4186432K), 1.8407840 secs]
2021年 11月 18日 星期四 13:34:15 CST
2021年 11月 18日 星期四 13:34:16 CST
2021年 11月 18日 星期四 09:37:53 CST
2021年 11月 18日 星期四 09:37:54 CST
108283 [Full GC 2802981K->408494K(4185408K), 2.1021330 secs]
2021年 11月 18日 星期四 09:37:55 CST
2021年 11月 18日 星期四 09:37:56 CST
2021年 11月 18日 星期四 22:02:50 CST
2021年 11月 18日 星期四 22:02:51 CST
136707 [Full GC 1554104K->281707K(4187776K), 1.7821050 secs]
2021年 11月 18日 星期四 22:02:52 CST
2021年 11月 18日 星期四 22:02:53 CST
2021年 11月 18日 星期四 10:16:54 CST
2021年 11月 18日 星期四 10:16:55 CST
110177 [Full GC 2803627K->412350K(4184448K), 1.7594870 secs]
2021年 11月 18日 星期四 10:16:56 CST
2021年 11月 18日 星期四 10:16:57 CST
高峰时段Full GC触发频率高,当老年代达到2.8G时,触发Full GC。
Young GC剩余对象如下图:
闲时段间隔一小时执行一次FGC
进程服务堆信息如下图
问题优化:
1、减少JVM触发Full GC频率,建议将应用服务堆大小调到6GB,新生代大小为3GB,新生代比例4:1:1,S0,S1各为500M左右,从目前Young GC未回收完的对象还是比较大,让对象在新生代得以充分回收。其次就是将GCThread线程数配置与CPU数量保持一致,11月10日配置值为8,生产实际CPU数为16,11月19日通过应用维护调优后,已经配置GCThread线程数为16。
2、由于JVM优化1只是减少FGC的频率,但是也避免不了FGC,为了减少JVM本身垃圾回收耗时影响业务交易耗时,建议调整整JVM垃圾回收机制由ParallelGC更改为CMS,由于CMS只会在初始标记和重新标记阶段触发短暂STW,其他阶段(并发标记预清理、并发清理、并发重置)都是与业务线程并行执行,整体缩短Full GC耗时时长。CMS不足会产生内存碎片,需要开启内存碎片整理和压缩机制。