应用周期性fullgc问题排查(2)

一、背景

     上次分析了某应用生产环境周期性fullgc问题,具体参考应用真线周期性fullgc问题(1),不过定位到该问题的原因也是比较巧合,刚好网上遇到了类似周期性fullgc的问题,所以可以准确定位到是cxf包引入导致的,这就类似于反正法,我知道了结果,然后我去证明该应用周期性fullgc是由于该问题引起的;上文结尾也给出了几种正向排查的方法,将fullgc时候的堆栈信息打印出来,以此来印证确实是cxf造成的。本次分析采用了btrace这一开源工具准确定位到调用System.gc的方法;

二、BTrace简介

     生产环境系统发生问题时,定位问题需要获取系统运行时的相关数据,如方法参数、返回值、全局变量、堆栈信息等。为了获取这些数据,需要修改代码,将数据输出到日志文件,再发布到生产环境。这种方式,一方面将增大定位问题的成本和周期,对于紧急问题无法做到及时定位及解决;另一方面重新部署后环境很大程度上已被破坏,很难重现问题。BTrace在这种背景环境下应运而生了。Btrace (Byte Trace)是sun推出的一款Java 动态、安全追踪(监控)工具,可以在不停机的情况下监控系统运行情况,并且做到最少的侵入,占用最少的系统资源。BTrace通过动态(字节码)检测正在运行的Java程序的类来工作。BTrace将跟踪操作插入到正在运行的Java程序的类中,并对跟踪的程序类进行热交换。github:https://github.com/btraceio/btrace。BTrace在使用上做了很多限制,如不能创建对象、不能使用数组、不能抛出或捕获异常、不能使用循环、不能使用synchronized关键字、脚本的属性和方法都必须使用static修饰等,具体限制条件可参考用户手册。如果想深入了解,可以网上自行查找,相关资料比较多;

三、BTrace本地使用

      3.1 首先是要下载Btrace相关的jar包,目前github上最新的是V2.0.0,也可以下载源码,自行编译打包(不过源码不是maven项目是gradle项目);

图1 Btrace最新版V2.0.0

网上找了一个V1.3.11.3的版本,与V2.0.0最大的区别就是类路径做了调整,老版的在com.sun.btrace包下,新版的在org.openjdk.btrace下面;其他更为详细区别可以看github上的介绍;
3.2 配置环境变量
sudo vi ~/.bash_profile
图2 配置jdk、btrace环境变量

source ~/.bash_profile 使配置生效
echo $PATH 查看配置是否生效
3.3 写监听脚本
图3 btrace监听脚本

图4 btrace-bin包结构

      直接使用build里面已经打包好的jar包,如上图BtraceTest就是一个监听类,monitor方法表示的是监听所有调用System.gc的方法,将其调用栈详细打印出来;当然还有好多其他用法,请自行查看相关资料,本文不再扩展;
另:最好在脚本里面只使用btrace和jdk包下的类,使用其他的在运行的时候可能会报找不到该类的错误(当然也有对应的解决办法。。。。。。);
注:脚本可以不需要放在需要排查的项目里,可以在任意目录下创建,这样使用btrace可以实现对业务代码的零侵入性,对业务代码而言是无感知的,这样就可以做到上面提到的在不停机的情况下监控系统运行情况;
3.4 运行脚本
先运行需要观测的应用,jps获取对应的进程号如图5,运行脚本如图6:
/Users/xxx/Documents/btrace-bin/bin/btrace -v 12595 /Users/xxx/IdeaProjects/myProjects/easyexcel/easyexcel-boot/src/main/java/cn/com/lyd/easyexcel/boot/scripts/BtraceTest.java (进程号不一致,是因为截图时间不一样,忽略哈。。。)
图5 获取项目运行的进程号

图6 执行btrace脚本

3.6 排查分析
由图6可知可以定位到是sun.misc.GC这个类下的内部静态类Daemon,这是一个守护线程:
图7 调用System.gc的源码

      图7这个和上次分析定位到一致,具体源码解析,可以参考应用周期性fullgc问题(1)
那么具体是哪里创建了该线程,接下去使用2种方法进行分析定位:
方法一:
图8 Gc.requestLatebcy方法

根据调用链路可知Gc类中创建Daemon守护线程的的是图8中的requestLatebcy方法,
图9 requestLatebcy方法调用

由图9可以看到requestLatebcy方法有2处调用,分别是图10的JDKBugHacks和图11的JreMemoryLeakPreventionListener
图10 JDKBugHacks类

图11 JreMemoryLeakPreventionListener类

由上次应用周期性fullgc问题(1)中分析可知,requestLatebcy方法的入参就是fullgc的周期,结合由图10、11的入参,真线上周期是10小时,因此可知调用requestLatebcy创建线程的就是JDKBugHacks类的doHacks方法;
方法二:
其实定位是哪个地方调用了线程的create方法,除了上面介绍的常规方法,还可以使用本文介绍的btrace方法,添加监听脚本
图12 监听sun.misc.Gc.Daemon线程的create方法

图13 btrace打印出的调用栈

如图13,根据btrace打印出来的调用链路,可以非常清晰的知道就是apache下的cxf包的JDKBugs.doHacks创建了该线程如图14,spring框架在初始化加载的时候调用了cxf包下的类,这就是为什么引入了该包,项目中没有使用到,但是却会调用JDKBugs.doHacks方法的原因;
图14 JDKBugs.dohacks方法

执行脚本的时候,项目刚启动的时候没有进行fullgc,这个也是比较困惑的,其实真线每次启动的时候是有fullgc一次的,但是本地却没有出现,查看源码分析,是由于GC.maxObjectInspectionAge(),如图15这个值会决定第一次会不会执行System.gc,每次启动该值都是不一样的,由于这个值是native修饰的,不知道具体的实现逻辑,所以只能先前一晚9点多开始跑,然后等到第二天7点多在查看运行结果;
图15 Daemon线程

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

推荐阅读更多精彩内容