java每隔一小时fullgc_JVM菜鸟进阶高手之路六（JVM每隔一小时执行一次FullGC）

以为上次问题是rmi的问题就此结束了&＃xff0c;但是问题并没有结束&＃xff0c;其实本次问题不是rmi问题导致的&＃xff0c;但是rmi也的确可能会有sys.gc fullgc问题。

查看GC统计汇总情况&＃xff1a;

jstat -gcutil pid 3s30

参考gc&＃xff0c;发现大概一小时运行一次FGC&＃xff0c;特别奇怪&＃xff0c;笨神一看这样的问题就知道是system gc导致的

System.gc()的默认效果是引发一次stop-the-world的full GC&＃xff0c;对整个GC堆做收集。用-XX:&＃43;DisableExplicitGC参数后&＃xff0c;System.gc()的调用就会变成一个空调用&＃xff0c;完全不会触发任何GC。

问题来了 如果直接使用-XX:&＃43;DisableExplicitGC就没有下面的任何事情了&＃xff0c;在测试过程中的确使用了该参数&＃xff0c;的确不会有full gc了。但是有写堆外空间的释放是需要涉及到System.gc的&＃xff0c;如果禁用可能见到direct memory的OOM类似的异常&＃xff0c;由于各种原因我们的环境没有禁用。由于没有禁用&＃xff0c;添加参数-XX:&＃43;ExplicitGCInvokesConcurrent 该方法可以指定System.gc()采用 CMS 算法&＃xff0c;FGC时停机时间会变短&＃xff0c;但是CMS GC次数不会变。通过该参数 经过观察日志效果比Full GC要好些。

看到这里一切都挺完美&＃xff0c;后面开始要到高潮了&＃xff0c;纠结…………看上篇文章里面有说一直以为是rmi问题&＃xff0c;就查找资料想让时间延迟下执行&＃xff0c;

-Dsun.rmi.dgc.client.gcInterval&＃61;36000000

-Dsun.rmi.dgc.server.gcInterval&＃61;36000000复制

单位是毫秒&＃xff0c;可适当延长触发FGC的定时时间间隔。 文中配置为10小时。通过jstack查看JVM线程

GC Daemon" daemon prio&＃61;10 tid&＃61;0x00007f91bcccf800 nid&＃61;0x37f0 in Object.wait() [0x00007f9182706000]

java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

- waiting on <0x0000000600021a48> (a sun.misc.GC$LatencyLock)

at sun.misc.GC$Daemon.run(GC.java:117)

- locked <0x0000000600021a48> (a sun.misc.GC$LatencyLock)

Locked ownable synchronizers:

- None复制

笨神告诉我们&＃xff0c;如果该线程一旦创建了就会间隔的调用gc了&＃xff0c;所以就会存在定时继续full gc问题。一直通过观察居然没有效果&＃xff0c;还是会一小时执行一个full gc。通过gc日志可以出出来&＃xff1a;

而且old区6g才占2.5G就background cms gc了

修改为cms的时候&＃xff0c;每次System.gc 一次full gc的时候cms gc还会加2的&＃xff0c;触发的是background cms gc如果不是后台就会一次&＃xff0c;cms过程如下&＃xff1a;

里面有一些概念比较重要&＃xff0c;并行和并发的定义。gc这个场景下 你可以这么记 并发表示gc线程可以和业务线程同时跑 并行表示gc线程跑的时候业务线程都全不能跑 。

在Java 9 中将 Java 8 默认的 GC 从 Parallel GC 改为 G1&＃xff0c;cms不是和ps比速度的&＃xff0c;cms是低延时垃圾回收器。

开始纠结了笨神告诉需要通过btrace跟踪下就很容易定位到问题那里调用了System.gc,根据ak大神提供的地址&＃xff0c;之后阿飞给了我关于btrace新的github地址&＃xff1a;https://github.com/btraceio/btrace以及一些Sample参考&＃xff1a;https://github.com/btraceio/btrace/tree/master/samples github官网很多参考样例&＃xff0c;基本上能覆盖常用的需求编写了查看gc代码如下&＃xff1a;

&＃64;OnMethod(clazz &＃61;"java.lang.System",method &＃61;"gc")

public static void onSystemGC(){

println("entered System.gc()");

jstack(); }复制

在本地调用模拟结果如下&＃xff1a;

放到环境进行观察&＃xff0c;也获取到了结果如下&＃xff1a;

打印到这里 知道是sun.misc.GC调用的&＃xff0c;在这里走了很多弯路了&＃xff0c;后来我把rmi去掉了&＃xff0c;但是还是一小时一次通过日志观察&＃xff0c;后来搜索发现tomcat文章&＃xff0c;

的确有&＃xff0c;开始也没有注意&＃xff0c;以为是这个原因&＃xff0c;修改了重试还是不行&＃xff0c;后是一波折过程&＃xff0c;后来查看jar文件&＃xff0c;的确不是一小时了&＃xff0c;

后来又看见

以为这个包问题&＃xff0c;又是一波修改&＃xff0c;发现还是一小时执行一次通过日志观察&＃xff0c;此时我已经无语了&＃xff0c;不过还好在我的坚持下&＃xff0c;还是把问题找到了&＃xff0c;由于我把项目去掉跑不会有&＃xff0c;那么感觉和项目有关&＃xff0c;但是代码里面的确没有调用&＃xff0c;我怀疑是否是其他jar里面的问题呢&＃xff1f;我把所有的jar都查了一遍&＃xff0c;的确发现问题了。

查看该jar

由于包的确有点老了&＃xff0c;里面的确是这样&＃xff0c;和上面的tomcat那个bug很像&＃xff0c;我下载了一个新版本查看&＃xff0c;发现的确优化了。

新版本里面变成了10个小时一次了&＃xff0c;而且可以通过jvm参数让其进行关闭&＃xff0c;-Dorg.apache.cxf.JDKBugHacks.gcRequestLatency&＃61;true即可。这次的这个一小时问题排除就结束了&＃xff0c;还需要修改代码&＃xff0c;后续继续观察&＃xff0c;在此过程中&＃xff0c;ak大神和阿飞都告诉我关于ygc时间问题&＃xff0c;的确这个还一直在实验&＃xff0c;希望优化的更好&＃xff0c;内容很多一直也在学习&＃xff0c;定位问题就是需要大胆的猜之后试之后优化修改记录。