一次线上服务fullGC原因排查

2017年12月09日 21:39:46

阅读数：384

一、现象

早上九点多又收到了fullGC次数过高的应用监控告警{P1}{故障}JVM Old GC all(#3) full_gc_count  >5}{当前值:28}，通过公司使用的监控平台可以观察到服务器在这个时间段内确实出现了一些异常情况：

1.负载突然增加

2.fullgc频率显著增加，每次时间渐渐增长

3.老年代内存使用率增长很快（大量对象直接进入老年带），可以看到Survivor区一直被打满（Survivor功效丧失，大量新生代对象不能及时回收越过Survivor直接进入年老代）

二、工具排查

线上日志dump

使用jmap -dump:live,format=b,file=xxx [pid]

工具介绍

市面上提供了很多种工具比如visualVM、JMAT、Jprofile和ha等工具，都可以进行内存堆快照文件分析

1、Jprofile

使用Jprofile需要先将文件后缀修改为hprof，用Jprofile可以一目了然的看出是大量对象，而且可以看到具体的方法一级classloader信息

2、ha

使用ha工具需要将dump文件后缀修改为jvmdump结尾，通过ha.jar工具查看可以看到大对象数量为66万多和38万多，分别占用了300多兆和65多兆堆内存

3、JMAT

JMAT也是很好用的工具，建议安装了eclipse的使用

4、visualVM

这里不建议用visualVM分析，一个需要设置出展示具体的方法或者对象（没研究出来），而且默认的内存空间比较小，要看大对象需要修改参数

经过试验后，对于dump文件分析最好是用Jprofile或者ibm出的ha.jar这个工具或者进行分析效果较好

 

三、排查结果分析

1、分析结果验证

根据工具分析结果，对照着监控中的异常可以看到9点11分时候三次long-SQL中查询返回了大量对象发现结果和时间都是吻合的，于是进一步排查代码

2、代码排查

排查过程中发现项目中并没有类似分类服务调用及SQL查询，是由于依赖的jar包中的方法有查询数据库，用的是本地缓存的形式，有个定时器类会从lion配置定时读取信息，
缓存过期时间设置的是3600000s，

查到原因这个服务没有人重新发布部署过，所以经过四十一天后缓存过期后，再初始化缓存时会重新读数据库获取所有分类和城市的数据，两次查询分别获取了六十多万分类与城市对应关系的对象，由于数量多，申请堆空间过大，所以大量对象直接进入了老年代，触发了fullGC

 

四、解决

这个方法是老的架构组件中方法并且已经很久没人维护，后续这类商区服务的实现方式需要重构，去掉了本地缓存和直接读取数据库的方法，改为分页调用不是直接查缓存