Jira大面積用戶響應(yīng)超時
背景
在上一章中，記錄了Confluence內(nèi)存泄漏故障的排查過程。同樣是用來作為團(tuán)隊協(xié)同開發(fā)管理平臺的重要組件Jira也遇到了問題，本文將會針對Jira系統(tǒng)故障的排查過程進(jìn)行記錄分享。根據(jù)Jira管理員描述，每次Jira運行兩周左右就會出現(xiàn)響應(yīng)特別緩慢的情況，需要重啟才能恢復(fù)。
問題排查過程
已知信息
- jira服務(wù)器的IP、賬號和密碼
- jira上次故障時間
- 故障可以周期性復(fù)現(xiàn)
- jira日?；臼褂媒?jīng)驗
信息收集
- 熟悉環(huán)境，獲取包括運行環(huán)境、JDK版本、程序部署目錄、程序啟動參數(shù)等信息?？梢酝ㄟ^ps查看進(jìn)程獲取大量有用信息。
- 查看日志和配置文件
- 添加修改參數(shù)，以備在下次故障時獲取更多信息
初次判斷
在初次信息收集的過程中，其實并沒有查到任何能直接判斷導(dǎo)致響應(yīng)緩慢的直接原因，反而因為很多信息誤導(dǎo)排查的方向。
Jira也是一個tomcat的web工程，使用的是jre1.8，同時為了滿足平臺級的整合，平臺集成時使用crowd、mysql、fisheye、sonar等等。在出現(xiàn)故障比較明顯當(dāng)天，日志中crowd數(shù)據(jù)同步時間超時、mysql連接異常、fisheye連接異常，但這些但不能確定就是故障產(chǎn)生的原因，可能是因為系統(tǒng)慢隨之產(chǎn)生的問題現(xiàn)象。
而且由于啟動參數(shù)中并沒有加入gc日志輸出，所以也不能直觀判斷JVM狀況。所以在setenv.sh里面加入配置-XX:+PrintGCDateStamps -XX:+PrintHeapAtGC，用來輸出gc日志。重啟Jira后等待下一個周期的故障出現(xiàn)。
故障再現(xiàn)
過了一周多就接到j(luò)ira管理員的電話，jira又出現(xiàn)了響應(yīng)緩慢超時的狀況。首先登入服務(wù)器查看， 首先GC日志是完全正常的，所以可以排除堆內(nèi)存問題。
之后就猜測是否是線程的問題，例如生成的線程數(shù)過多、數(shù)據(jù)庫連接數(shù)過多等等，使用了例如pstree -p `ps -e | grep jira | awk '{print $1}'`|wc -l等指令進(jìn)行了逐個排查，但都沒有明顯異常。直到突然想到執(zhí)行了一下top命令，才發(fā)現(xiàn)進(jìn)程占用CPU特別高，所以故障排查除了技術(shù)，運氣也很重要！
CPU高排查流程
- 實時查看jira中占用cpu最高的線程，執(zhí)行指令top -H -p pid，shift+p按照CPU排序
thread-cpu-top - 生成stack信息，執(zhí)行指令jstack -l pid >>jstack.log生成stack信息
- 將問題進(jìn)程號轉(zhuǎn)換為16進(jìn)制，執(zhí)行指令printf "%x\n" tid, 將線程號轉(zhuǎn)換為16進(jìn)制
-
根據(jù)線程號在jstack.log中查找具體的問題線程，如下圖全是C2 Compiler線程導(dǎo)致的
jstack.log
分析
C1 Compiler和C2 Compiler是Java HotSpot VM中的JIT編譯器（也叫Opto編譯器），C1 Compiler是客戶端編譯器，C2 Compiler是服務(wù)端編譯器，JIT編譯器是運行時即時編譯器。javac將java文件編譯成字節(jié)碼的class文件，在java最初始的版本是被認(rèn)為是一個解釋執(zhí)行的語言，也就是JVM解釋器（interpreted）會將字節(jié)碼逐條解釋翻譯成機(jī)器可識別的機(jī)器指令，形成指令流逐條執(zhí)行。而JIT是將字節(jié)碼編譯成本地代碼緩存起來（還會有一些優(yōu)化操作），以達(dá)到更快的執(zhí)行效率。
JVM就存在這么一個常常被忽視的內(nèi)存區(qū)域，也就是“代碼緩存”，它是用來存儲已編譯方法生成的本地代碼。代碼緩存一般不會出問題，但當(dāng)代碼緩存被占滿的時候，問題往往是毀滅性的。首先會打印一條警告信息，但是這之后并不會馬上導(dǎo)致系統(tǒng)出現(xiàn)問題，往往會在系統(tǒng)繁忙或者累積一段時間后才會緩慢到讓人發(fā)覺。本例中從異常出現(xiàn)到用戶反映，中間間隔了有四五天時間，這也增加了故障排查的難度。
理論上講code cache區(qū)滿之后，會切換到interpreted-only模式。HotSpot的默認(rèn)模式是混合模式，即解釋器和編譯器混合使用的，兩者混合使用的策略這里就不在描述了。切換到解釋器即interpreted-only模式是會導(dǎo)致運行速度的降低，但是不應(yīng)該導(dǎo)致CPU接近100%的占用，通過google可以發(fā)現(xiàn)可能是jdk版本的bug導(dǎo)致的，jdk9之后才會修復(fù)。
總結(jié)
至此，故障的原因已經(jīng)能夠確認(rèn)了，是由于code cache去被占滿，JVM切換到interpreted-only模式導(dǎo)致運行性能大幅下降，同時由于JDK版本bug，cpu占用越來越高，加劇降低程序的運行性能導(dǎo)致服務(wù)基本不可用只能重啟恢復(fù)。
解決辦法是添加-XX:ReservedCodeCacheSize提高設(shè)置code cache大小，提高代碼的緩存大小只會延緩其發(fā)生溢出。所以同時添加-XX:+UseCodeCacheFlushing參數(shù)，當(dāng)代碼緩存被填滿時讓JVM放棄一些編譯代碼。
本例中用到了一些故障排查中常用的指令、JAVA程序CPU高排查一般流程、JVM解釋器和編譯器，當(dāng)然還有必不可少的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
