项目周期性fullGc 间隔为1小时

现象:

image

可以看到fullGc间隔时间为1小时.

同事看到这个现象后反馈说,这可能和tomcat的版本过低有关系.tomcat6.0为了避免内在溢出会通过system.gc()触发fullGc, 建议我们升级tomcat. 于是确认了一下,发现jdk和tomcat的版本信息为

image

确实是非常低,无论如何也该升级了. 在升级前当然要先看看fullGc的原因了.于是通过

-XX:+PrintGCDetails
输出gc信息,这个默认是输出到控制台的,所以在catalina.out中也是可以看到的.

image

可以看到老年代根本没有达到最大值,通过[Full GC (System)也能说明fullGc是通过System.gc()调用的

关于触发的详细细节请戳这里:http://www.linkedkeeper.com/1330.html

于是升级到jdk1.8 ,tomcat8.0 ,启动,本以为就此结束,没想到系统在启动时就先来了三次fullGc,这还真是个惊喜.

通过 jstat -gcutil pid 1000 5 查看如下

image

输出的日志信息如下

image

full gc 原因都是一样的: MetaData GC Threshold , 通过查阅资料及现场日志可以看出是Metaspace空间不够了,扩了三次.发生了三次fullGc
Metaspace 默认为20M左右,通过日志信息可以看出来
于是设定Metaspace大小
-XX:MetaspaceSize=128M
再次重启,果然不在full Gc了,经过一段时间的监控,发现不会在频繁fullGc了

image

本以为周期性fullGc问题就这样结束时,新的问题接踵而来.

在升级另一个项目的jdk及tomcat版本后,惊奇的发现又出现了周期性fullGc的问题,间隔时间还是一个小时.而且项目在启动时就会来一次fullGc

image

这就纳闷了,我tomcat已经升级到8.0了,怎么还会出现呢? 没关系,把上面排查的路在走一遍.

1,查看gc日志

image

发现是system.gc().

2,排查tomcat,发现已经不存在之前的问题.

3,尝试本地复现
本地成功复现,周期也为1小时. 猜测可能是某个组件导致的,因为太规律了,但靠猜站不住脚,还得去跟踪.

使用VisualVM 跟踪这个进程,先看下有没有特殊的线程,发现有个 GC Daemon 的守护线程

image

有经验的同事可能已经从线程的堆栈信息中看出门道了.但我这时还没有察觉.

于是引入了BTrace, BTrace功能很强大,可以方便的获取程序运行时的数据信息，如方法参数、返回值、全局变量和堆栈信息等. 在VisualVM中有BTrace的插件,直接安装就可以.

image

然后打开.

image

出现这个界面

image

然后输入以下代码:

/* BTrace Script Template */
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace
public class TracingScript {
    /* put your code here */
  @OnMethod(clazz = "java.lang.System", method = "gc")
  public static void onSystemGC() {
      println("entered System.gc()");
      jstack();
  }
}

java.lang.System 是我们要跟踪的类, gc是system中的方法名. 因为gc日志中显示是通过这个方法调用的. jstack() 是打出堆栈信息
然后点上面的start