原文地址:http://www.eussi.top/view/16
一、问题描述
生产运行跟踪过程中,遇到FullGC次数过多的问题。于是在测试环境将GC日志详细打印出来进行重现,主要表现如下:
- YGC正常,当Eden区即将满之后进行YGC
- FGC出现的现象很奇怪,老年代内存还有相当大的空间,整个年轻代装进老年代都不是问题,但是很奇怪却出现了FGC。
- 长时间运行下去老年代内存也没有因为越积越多出现内存泄漏
- FGC一天大概出现了二十多次的FGC,通过查看GC日志,并未满足FGC因为堆内存方面的触发条件
- FGC很规律,定时在每小时的某个时间点触发FGC
二、问题查找
- 最初未看出FGC规律进行,于是查找相关资料查找触发FGC的各种原因,所有的条件排除之后,就只剩下直接调用System.gc()的可能,但是最初认为应用的开发过程中并未使用到System.gc()的调用,这个同样也是不可能的情况。
- 经过再次分析GC日志,发现FGC是规律进行的,每个小时均会运行一次,于是猜想是不是Jdk使用的不同的垃圾收集器中有些垃圾收集行为是每小时一次,但是经过查找相关资料,还是未找到任何资料,排除垃圾收集器的问题。
- 于是通过jstat -gccause进行观察,查看导致FGC的原因,如下图,发现是调用了System.gc()导致。
- 前面的分析,可以确定一定是代码中规律的显示调用了System.gc(),也许不是我们开发的代码,而是集成的第三方jar中调用的。既然调用了System.gc(),通过调试代码FGC时必定运行到gc()方法处,于是在该处打上断点,发现的确是显示调用了System.gc(),如下图。可以看出是在一个名为GC Daemon的守护线程中,sun.misc.GC调用了System.gc()造成的FGC。
- 进一步看下去,需要查找谁创建了该线程,在GC类的各个方法上断点debug,运行结果如下图,可以看出几个关键的类,GC和GCClient,其中GC.requestLatency(long)方法会出入一个数字,通过调试发现是3600000L,正好是一小时,通过此方法,会创建GC Daemon线程,DGCClient中会获取系统变量“sun.rmi.dgc.client.gcInterval”(默认一小时),传入GC。于是出现了之前的FGC现象
- 最终是要看一下具体是哪个包调用了这个类,发现是由于使用了RMI造成的。
三、解决方式
通过查阅网上资料,给出以下解决方式:
- 增加参数 -XX:+DisableExplicitGC,这样System.gc()的调用就会变成一个空调用。但是该方法不适用在大量使用NIO的direct memory,网上可以看到很多使用此参数后,再使用netty造成的内存溢出问题,慎用。
- 通过代码可以看出通过增加参数 -Dsun.rmi.dgc.client.gcInterval=3600000 减少FGC, 其中3600000即为定时触发的时间间隔设置,单位是毫秒,即延长触发FGC的定时时间间隔。
- 增加参数 -XX:+ExplicitGCInvokesConcurrent 或者-XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses该方法可以指定System.gc()采用 CMS 算法,FGC时停机时间会变短,但是CMS GC次数不会变,仍然是1小时1次。