记一次排查线上频繁FullGC 过程

一、一段艰辛的排查过程

记录一次生产环境频繁FullGC的排查过程，艰辛但收获满满；

1.突发告警

这是一个风和日丽的下午，已经疲惫不堪的我正日常码代码，突然收到JVM监控告警，进入监控大盘查看JVM情况：

1.1 新生代老年代情况：

图片截了一张最简化的出来，因为公司数据安全限制；

蓝色：新生代
棕黄色：老年代
从图线中可以看出，新生代是在某一时刻突然被打满的，这种情况猜测可能是产生了死循环、批量导出等问题；

1.2 老年代GC情况

图线呈阶梯递增趋势，表明频繁 FullGC，但问题就在，频繁FullGC而GC不掉对象，说明这些对象还存在Roots；

2.紧急处理

在公司的一条军规：先恢复，再定位；先恢复服务的可用，再来定位问题的原因；
我的服务是多节点部署，通过公司网关做负载均衡：

1. 周知 PM下线 XX节点；
2. 网关下线XX节点服务；
3. 生成dump文件 jmap -dump:live,format=b,file=dump.hprof 进程号；
4. 重启服务，恢复可用；

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导致的生产问题，但整个过程下来，也学到了非常多的知识；也感谢同事的相助；