记一次排查线上频繁FullGC 过程
-
- 一、一段艰辛的排查过程
-
- 1.突发告警
-
- 1.1 新生代老年代情况：
- 1.2 老年代GC情况
- 2.紧急处理
- 3.问题定位
-
- 3.1 dump文件过大：
- 3.2 如何分析：
- 3.3 排查原因
- 3.4 水落石出
- 4.修复上线
- 二、收获
一、一段艰辛的排查过程
记录一次生产环境频繁FullGC的排查过程，艰辛但收获满满；
1.突发告警
这是一个风和日丽的下午，已经疲惫不堪的我正日常码代码，突然收到JVM监控告警，进入监控大盘查看JVM情况：
1.1 新生代老年代情况：
图片截了一张最简化的出来，因为公司数据安全限制；
蓝色：新生代
棕黄色：老年代
从图线中可以看出，新生代是在某一时刻突然被打满的，这种情况猜测可能是产生了死循环、批量导出等问题；
1.2 老年代GC情况
图线呈阶梯递增趋势，表明频繁 FullGC，但问题就在，频繁FullGC而GC不掉对象，说明这些对象还存在Roots；
2.紧急处理
在公司的一条军规：先恢复，再定位；先恢复服务的可用，再来定位问题的原因；
我的服务是多节点部署，通过公司网关做负载均衡：
- 周知 PM下线 XX节点；
- 网关下线XX节点服务；
- 生成dump文件 jmap -dump:live,format=b,file=dump.hprof 进程号；
- 重启服务，恢复可用；
3.问题定位
登录服务器查看生成的 dump文件，大小有29G，面对的第一个问题来了；
3.1 dump文件过大：
分析dump文件，是需要内存来支撑的，而29G的内存就算拿到本地电脑也无法分析，所以我找运维同学申请了一台新服务器(130G内存)，将29G的dump压缩，压缩zip包之后大概5G，发送到新服务器；
3.2 如何分析：
1.下载Linux版本的MAT
2.下载后解压，进到MAT目录中，执行：
修改MAT JVM参数
MemoryAnalyzer.ini 调整堆大小可以容纳你的dump文件的大小
./ParseHeapDump.sh jmap.info org.eclipse.mat.api:suspects org.eclipse.mat.api:overview org.eclipse.mat.api:top_components
3.上述命令我大概等了2个小时，生成了三个压缩包文件：
jmap_Leak_Suspects.zip
jmap_System_Overview.zip
jmap_Top_Components.zip
在生成报告的这2个小时的时间里，排查链路追踪日志、查看网关请求日志、都没有查到可疑问题；将所有的希望都寄托在了报告上；
3.3 排查原因
终于生成了报告：
报告中提示有一个问题，占用了23.4G内存，下面的问题怀疑也没有给也直接的原因，点击See stacktrace：
栈信息中可以看出，是调用系统中的一个Excel转PDF的工具导致的；aspose是一个专门做文档转换的一个工具
3.4 水落石出
既然是Excel转换PDF导致的，那就查下当前时间段系统中记录的上传日志，有一个时间点比较符合的Excel，拿到上传到OSS的链接，下载到本地（文件非秘密文档）跑单测，本地运行报OOM，果然是这个文件的问题；
原因： 用户上传的Excel对多行整列加了底色，比如这种：
然后导致aspose解析时，认为有底色的列就有数据，造成一直FullGC；
4.修复上线
问题定位到了，和PM确认后，下线了Excel转换PDF的功能；
本来打算限制行和列的个数，后来看系统上传的Excel格式乱七八糟，竟然也有几万行的；
二、收获
我的系统上游对接了很多的业务系统，出现问题后收到各方反馈，一方面顶住压力，另一方面及时向各级领导反馈原因；
整个排查过程，艰辛，未接触过 JVM导致的生产问题，但整个过程下来，也学到了非常多的知识；也感谢同事的相助；