陌生系统故障排查记录(二)-Jira大面积用户响应超时

Jira大面积用户响应超时

背景

在上一章中,记录了Confluence内存泄漏故障的排查过程。同样是用来作为团队协同开发管理平台的重要组件Jira也遇到了问题,本文将会针对Jira系统故障的排查过程进行记录分享。根据Jira管理员描述,每次Jira运行两周左右就会出现响应特别缓慢的情况,需要重启才能恢复。

问题排查过程

已知信息

  • jira服务器的IP、账号和密码
  • jira上次故障时间
  • 故障可以周期性复现
  • jira日常基本使用经验

信息收集

  1. 熟悉环境,获取包括运行环境、JDK版本、程序部署目录、程序启动参数等信息。可以通过ps查看进程获取大量有用信息。
  2. 查看日志和配置文件
  3. 添加修改参数,以备在下次故障时获取更多信息

初次判断

在初次信息收集的过程中,其实并没有查到任何能直接判断导致响应缓慢的直接原因,反而因为很多信息误导排查的方向。
Jira也是一个tomcat的web工程,使用的是jre1.8,同时为了满足平台级的整合,平台集成时使用crowd、mysql、fisheye、sonar等等。在出现故障比较明显当天,日志中crowd数据同步时间超时、mysql连接异常、fisheye连接异常,但这些但不能确定就是故障产生的原因,可能是因为系统慢随之产生的问题现象。
而且由于启动参数中并没有加入gc日志输出,所以也不能直观判断JVM状况。所以在setenv.sh里面加入配置-XX:+PrintGCDateStamps -XX:+PrintHeapAtGC,用来输出gc日志。重启Jira后等待下一个周期的故障出现。

故障再现

过了一周多就接到jira管理员的电话,jira又出现了响应缓慢超时的状况。首先登入服务器查看, 首先GC日志是完全正常的,所以可以排除堆内存问题。
之后就猜测是否是线程的问题,例如生成的线程数过多、数据库连接数过多等等,使用了例如pstree -p `ps -e | grep jira | awk '{print $1}'`|wc -l等指令进行了逐个排查,但都没有明显异常。直到突然想到执行了一下top命令,才发现进程占用CPU特别高,所以故障排查除了技术,运气也很重要!

CPU高排查流程

  1. 实时查看jira中占用cpu最高的线程,执行指令top -H -p pid,shift+p按照CPU排序
    thread-cpu-top
  2. 生成stack信息,执行指令jstack -l pid >>jstack.log生成stack信息
  3. 将问题进程号转换为16进制,执行指令printf "%x\n" tid, 将线程号转换为16进制
  4. 根据线程号在jstack.log中查找具体的问题线程,如下图全是C2 Compiler线程导致的


    jstack.log

分析

C1 Compiler和C2 Compiler是Java HotSpot VM中的JIT编译器(也叫Opto编译器),C1 Compiler是客户端编译器,C2 Compiler是服务端编译器,JIT编译器是运行时即时编译器。javac将java文件编译成字节码的class文件,在java最初始的版本是被认为是一个解释执行的语言,也就是JVM解释器(interpreted)会将字节码逐条解释翻译成机器可识别的机器指令,形成指令流逐条执行。而JIT是将字节码编译成本地代码缓存起来(还会有一些优化操作),以达到更快的执行效率。
JVM就存在这么一个常常被忽视的内存区域,也就是“代码缓存”,它是用来存储已编译方法生成的本地代码。代码缓存一般不会出问题,但当代码缓存被占满的时候,问题往往是毁灭性的。首先会打印一条警告信息,但是这之后并不会马上导致系统出现问题,往往会在系统繁忙或者累积一段时间后才会缓慢到让人发觉。本例中从异常出现到用户反映,中间间隔了有四五天时间,这也增加了故障排查的难度。


code cahe

理论上讲code cache区满之后,会切换到interpreted-only模式。HotSpot的默认模式是混合模式,即解释器和编译器混合使用的,两者混合使用的策略这里就不在描述了。切换到解释器即interpreted-only模式是会导致运行速度的降低,但是不应该导致CPU接近100%的占用,通过google可以发现可能是jdk版本的bug导致的,jdk9之后才会修复。


oracle jdk bug

总结

至此,故障的原因已经能够确认了,是由于code cache去被占满,JVM切换到interpreted-only模式导致运行性能大幅下降,同时由于JDK版本bug,cpu占用越来越高,加剧降低程序的运行性能导致服务基本不可用只能重启恢复。
解决办法是添加-XX:ReservedCodeCacheSize提高设置code cache大小,提高代码的缓存大小只会延缓其发生溢出。所以同时添加-XX:+UseCodeCacheFlushing参数,当代码缓存被填满时让JVM放弃一些编译代码。
本例中用到了一些故障排查中常用的指令、JAVA程序CPU高排查一般流程、JVM解释器和编译器,当然还有必不可少的google以及一点点运气。

参考

https://confluence.atlassian.com/jirakb/jira-crashes-due-to-codecache-is-full-compiler-has-been-disabled-314447083.html
https://answers.atlassian.com/questions/22651310/c1c2-compiler-thread-eats-a-lot-of-cpu
http://blogs.atlassian.com/2012/05/codecache-is-full-compiler-has-been-disabled/
http://bugs.java.com/view_bug.do?bug_id=8041984

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

推荐阅读更多精彩内容