项目周期性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

image

出现下面的 ** BTrace up&running就明在正常运行了,这样当System.gc()被调用的时候就会打出堆栈信息.

结果如下 (发生两次fullGc)


image

可以发现是sun.misc.GC调用了这个线程.这个与刚刚 Thread中的信息其实是一致的.

于是项目中搜索这个关键字,不要忘记jar包也要排查.

排查到在cxf-common-utilities-2.2.10.jar 的JDKBugHacks 类中有调用


image

通过注释能够看出是为了防止可能的内存溢出而周期性调用.

看了下这个组件的新版本,对这块已经进行了优化


image

调整为10小时一次,同时增加了一个 控制参数 : -Dorg.apache.cxf.JDKBugHacks.gcRequestLatency=true ,在jvm参数上配置后即可不启用周期性fullGc.

这个apache cxf组件我没有用过,查阅后发现是和webservice有关的一个组件.本项目已经不在使用webservice,但代码没有梳理干净.于是排查下相关点,去掉了这个组件.再次预发布.


image

目前发现没有在fullGc了

总结:
1. 在软件项目的生命周期中,软件维护是最后一个阶段,也是持续时间最长,花费代价最大的一个阶段,确定无用的代码一定要及时清理,提升项目清洁度,降低后继运维成本.
2. 在升级jdk及tomcat时要考虑到其它组件的版本适配,虽然是向下兼容的,但还是要做好测试.


参考文档:

http://www.linkedkeeper.com/1330.html

https://blog.csdn.net/liubenlong007/article/details/78143285

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 215,723评论 6 498
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 92,003评论 3 391
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 161,512评论 0 351
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,825评论 1 290
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,874评论 6 388
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,841评论 1 295
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,812评论 3 416
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,582评论 0 271
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,033评论 1 308
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,309评论 2 331
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,450评论 1 345
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,158评论 5 341
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,789评论 3 325
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,409评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,609评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,440评论 2 368
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,357评论 2 352

推荐阅读更多精彩内容