频繁FGC的真凶原来是它

上周排查了一个线上问题,主要现象是CPU占用过高,jvm old区占用过高,同时频繁fgc,我简单排查了下就草草收场了,但是过后我对这个问题又进行了复查,发现问题没有那么简单,下面跟着我一起分析一下到底是怎么回事?

复查过程

复查原因

事后再看dump文件注意到最大的对象是一个ArrayList,里面几乎都是ElasticSearchStatusException对象

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

可是发生这个异常的操作上次已经被我定位到了,数据漏斗只有产品、运营等内部人员使用,通过使用频率推测,不应该有那么多对象。我猜想是不是代码中存在死循环,但没有找到。没办法只能在测试环境进行场景复现了。

复原现场

通过上次排查到是es查询了不存在的索引导致异常,所以就把查询es的索引写死一个不存在的,最初尝试写个单测,但一直不能复现问题,所以只好部署到测试环境,在本地通过远程debug 调试程序

远程debug到断点时,发现源码对不上

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

然后发现有可选择的源码,这里是关键

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

从org.apache.commons.lang:2.5jar包切换到springsource.org.apache.commons.lang:2.1.0包后,竟然能够和测试环境对得上,可是代码中明明引用的commons.lang:2.5的包,这里说明在项目中类加载的时候,ExceptionUtils这个class文件并不是从commons.lang中加载的,而是从springsource包中加载的 关于类文件加载的问题我们先放到后面,先找代码的问题

看到这里,眼尖的朋友应该已经发现了bug的所在,那么恭喜你。如果没发现的朋友,不要着急,跟我一步一步来。我们继续debug跟进代码的 getCause方法,可以看到通过遍历异常名字的数组验证是否在抛出的异常中存在

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

这些异常方法中的getRootCause方法,存在ElasticSearchStatusException的父类ElasticsearchException中

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

我们看下这个方法,主要找最根本的异常原因,有则返回,没有就返回当前的异常

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

继续跟代码,cause不为null,返回这个异常

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

bug代码定位

这个getThrowables方法,里面有个while循环,判断条件只进行了非空判断,不为null就添加到list中,注意观察我截图的时刻,list的大小 8万多,其实远远不止会看开头dump文件的大对象,是一个ArrayList,里面有大量的ElasticSearchStatusException对象

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

其实到这里已经定位到了FGC的真凶,判断条件没有排除返回的异常是已经添加到list中的异常,所以会一直循环添加,造成堆内存占用满了,FGC回收不掉这些对象,因为ArrayList一直持有他们的引用

正确代码应该如下面这样,所以开源工具库也是会有bug的,用的时候多加注意

public static Throwable[] getThrowables(Throwable throwable) {

List list = new ArrayList();

// 这里的判断条件应该加上 list.contains(throwable) == false

while (throwable != null && list.contains(throwable) == false) {

list.add(throwable);

throwable = ExceptionUtils.getCause(throwable);

}

return (Throwable[]) list.toArray(new Throwable[list.size()]);

}

本来我们就没想用springsource的方法,只是类加载的时候加载错了,那看下commons.lang包下的方法是否正确呢?可以看到这个包的方法是正确的,考虑到了这个问题

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

springsource的commons.lang包在2.2版本已经修复了这个问题 jar包最好引用最新的

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

class文件加载问题

上面我们留了一个jvm加载class文件的问题,我们知道jvm加载class的时候,如果存在包名和类名完全一样,先加载一个后,另外的就不会再被加载了。

经查看两个ExceptionUtils确实包名类名完全一致

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园 其实通过前面的debug和代码分析,已经能确定项目加载的ExceptionUtils.class文件来自springsource包,但还是想通过一定手段验证一下。

其实jvm提供类类似的功能参数,修改项目启动脚本,添加jvm参数 -XX:+TraceClassLoading 然后重启项目并继让异常重现【这里要让触发异常重现,是因为是运行时异常】,并查看日志,查看ExceptionUtils.class的加载信息

fgc java,频繁FGC的真凶原来是它-冯金伟博客园fgc java,频繁FGC的真凶原来是它-冯金伟博客园

可以看到确实和我们推测的一样

其实这里还可以深入研究jvm的类加载机制,类加载器加载顺序,双亲委派模型等

如何解决

通过 mvn dependency:tree 查看jar包依赖情况,排除掉不用的jar包

结尾

到这里这个问题的排查应该告一段落了,从排查过程中学到了不少,场景复现,梳理思路,用文章分享出来虽说码字不易很耗时,但这是对自己的一种总结,里面还是有很多乐趣与收获的。

后续会继续分享一些和广告系统相关的文章,敬请期待!

欢迎关注公众号 【每天晒白牙】,获取最新文章,我们一起交流,共同进步!