阿里開源Java診斷工具 Arthas 使用

Arthas 是阿里開源的 Java 診斷工具恋拷,相比 JDK 內(nèi)置的診斷工具准给,要更人性化,并且功能強(qiáng)大描滔,可以實(shí)現(xiàn)許多問題的一鍵定位棒妨,是我用到的最方便的診斷工具。
下載和安裝見官網(wǎng) https://arthas.aliyun.com/doc/profiler.html
下面記錄一些我工作中常用到的指令

1. dashboard : 展示當(dāng)前進(jìn)程信息

主要是兩部分: 線程信息(按照cpu使用率倒序) 和 內(nèi)存信息
可以快速發(fā)現(xiàn) 當(dāng)前前幾個(gè)cpu使用高的線程

image.png

2. thread :查看當(dāng)前 JVM 的線程堆棧信息

image.png
thread : 獲取當(dāng)前所有線程 (按照cpu使用率倒序) 
thread 4602 threathe : 獲取指定線程堆棧信息
thread -n 8 : 當(dāng)前最忙的前8個(gè)線程并打印堆棧
thread -n 8  -i 3000 : 列出3s內(nèi)最忙的8個(gè)線程并打印堆棧(-i 為采樣時(shí)間)
thread -b :找出當(dāng)前阻塞其他線程的線程
有時(shí)候我們發(fā)現(xiàn)應(yīng)用卡住了含长, 通常是由于某個(gè)線程拿住了某個(gè)鎖券腔, 并且其他線程都在等待這把鎖造成的。 
為了排查這類問題拘泞, arthas提供了thread -b纷纫, 一鍵找出那個(gè)罪魁禍?zhǔn)住?注意, 目前只支持找出synchronized關(guān)鍵字阻塞住的線程陪腌, 如果是java.util.concurrent.Lock辱魁, 目前還不支持。

3. heapdump : dump java heap, 類似jmap命令的heap dump功能诗鸭。

heapdump /tmp/dump.hprof : dump到指定文件

heapdump --live /tmp/dump.hprof : 只dump live對(duì)象

下載dump文件后染簇,可以使用MAT查看,MAT官網(wǎng)下載: https://www.eclipse.org/mat/previousReleases.php 强岸,主要要選擇和本地一樣的jvm版本锻弓,不然啟動(dòng)會(huì)失敗。

使用MAT 分析 OOM 大內(nèi)存問題蝌箍,過程如下青灼,是截取別的文章的過程。

image.png
image.png
image.png
image.png
image.png

4. watch: 觀察到指定函數(shù)的調(diào)用情況妓盲。能觀察到的范圍為:返回值杂拨、拋出異常、入?yún)?/h1>

這個(gè)用于觀察未打印日志的方法特別好用悯衬,包括入?yún)?返參 和 異常

watch xxx.xxx.ABTestRecordServiceImpl doABTestWithLayer "{params,returnObj}" -x 3 -n 2 
-x 指定輸出結(jié)果的屬性遍歷深度弹沽,默認(rèn)為 1,最大值是4 ,
如果入?yún)⒑统鰠⑹菍傩陨疃炔灰粯樱ㄍǔJ遣灰粯拥拇遥雲(yún)⒕褪且粋€(gè)對(duì)象,出差會(huì)統(tǒng)一被一個(gè)Result包裹)亏狰,需要分別設(shè)置才能觀察到
params,returnObj : 指的是入?yún)⒑头祬⒁畚疲潭ㄖ?throwExp :觀察異常信息 watch demo.MathGame primeFactors "{params,throwExp}" -e -x 2

-b :  在函數(shù)調(diào)用之前觀察入?yún)ⅲ驗(yàn)槿雲(yún)⒂锌赡茉趫?zhí)行被修改
-e :在函數(shù)異常之后觀察
-s : 在函數(shù)返回之后觀察暇唾,因?yàn)槿雲(yún)⒂锌赡茉趫?zhí)行被修改
-n :  表示執(zhí)行次數(shù)促脉,即只打印n次,對(duì)于頻繁調(diào)用來說策州,不設(shè)置的話瘸味,會(huì)打印很多

watch xxx.xxx.ABTestRecordServiceImpl doABTestWithLayer "{params,returnObj}" -x 3 -n 2  '#cost>100'
'#cost>100' : 按照耗時(shí)過濾,在很多方法中都可以通用够挂,表示只打印執(zhí)行超過100ms的方法
image.png

實(shí)例應(yīng)用:生產(chǎn)上一個(gè)已廢棄的接口突然被調(diào)用旁仿,報(bào)了一個(gè)異常,由于是老接口孽糖,我們并沒有catch捕獲枯冈,導(dǎo)致我們的日志filter沒能打印出入?yún)恚覀兿敫鶕?jù)入?yún)矶ㄎ皇悄睦镌谡{(diào)用办悟,是誰在調(diào)用尘奏,這時(shí)候就可以用 watch 來獲取方法的調(diào)用入?yún)ⅰ?br> 發(fā)現(xiàn)是運(yùn)營突然上線了一個(gè)很久都沒用的活動(dòng)導(dǎo)致的,我們直接下線就可以了病蛉。

5. trace: 渲染和統(tǒng)計(jì)整個(gè)調(diào)用鏈路上的所有性能開銷和追蹤調(diào)用鏈路炫加。

trace命令只會(huì)匹配到的函數(shù)里的子調(diào)用,并不會(huì)向下trace多層铺然。因?yàn)閠race是代價(jià)比較貴的俗孝,多層trace可能會(huì)導(dǎo)致最終要trace的類和函數(shù)非常多。

trace xxx.DiscountCXOpenServiceImpl aaaRespCXDTOList  '#cost > 50' -n 1
-n : 打印次數(shù)
'#cost>100' : 方法執(zhí)行耗時(shí)
默認(rèn)情況下魄健,trace不會(huì)包含jdk里的函數(shù)調(diào)用驹针,如果希望trace jdk里的函數(shù),需要顯式設(shè)置 --skipJDKMethod false诀艰。
image.png

6. stack:輸出當(dāng)前方法被調(diào)用的調(diào)用路徑

如果一個(gè)方法被很多地方調(diào)用了柬甥,但是我們又不知道是被哪里調(diào)用時(shí),可用這個(gè)命令查詢

stack xxx.DiscountCacheUtil getStrategyCachaaa  -n 1 
image.png

7. profiler:生成應(yīng)用熱點(diǎn)的火焰圖其垄。

profiler start : 啟動(dòng) 
    啟動(dòng)時(shí)苛蒲,默認(rèn)采樣的是cpu,可以通過 --event 來指定跟蹤事件(cpu , alloc , lock )
profiler status :查看狀態(tài) 
profiler stop : 停止
    停止時(shí)绿满,默認(rèn)生成html格式文件臂外,可以通過 --file 指定生成路徑和svg類型
image.png
image.png

從上面可以看出來耗時(shí)主要是在json parseArray格式化上。 橫向長度越長,說明耗時(shí)越久

火焰圖說明:火焰圖是基于 perf 結(jié)果產(chǎn)生的 SVG 圖片漏健,用來展示 CPU 的調(diào)用棧嚎货。

  • y 軸表示調(diào)用棧,每一層都是一個(gè)函數(shù)蔫浆。調(diào)用棧越深殖属,火焰就越高,頂部就是正在執(zhí)行的函數(shù)瓦盛,下方都是它的父函數(shù)洗显。

  • x 軸表示抽樣數(shù),如果一個(gè)函數(shù)在 x 軸占據(jù)的寬度越寬原环,就表示它被抽到的次數(shù)多挠唆,即執(zhí)行的時(shí)間長。注意嘱吗,x 軸不代表時(shí)間玄组,而是所有的調(diào)用棧合并后,按字母順序排列的谒麦。

火焰圖就是看頂層的哪個(gè)函數(shù)占據(jù)的寬度最大巧勤。只要有“平頂”(plateaus),就表示該函數(shù)可能存在性能問題弄匕。

顏色沒有特殊含義颅悉,因?yàn)榛鹧鎴D表示的是 CPU 的繁忙程度,所以一般選擇暖色調(diào)迁匠。

默認(rèn)生成的是html格式剩瓶,只是html格式找東西不方便


image.png

8. Arthas線上常用場景

8.1 CPU過高問題

現(xiàn)象描述:運(yùn)維突然打電話說是生成線上節(jié)點(diǎn)cpu高達(dá)80%,而且還在增加城丧,但是最新的一個(gè)版本并沒有什么復(fù)雜的功能上線延曙,而且日志在報(bào)一個(gè)批量插入主鍵沖突的異常,但是這個(gè)批量插入的功能已經(jīng)上線很久亡哄,并且在很多地方都有用到枝缔,所以不能定位到是哪里的問題,這時(shí)候可以用arthas來查找問題原因

//dashboard 命令用于整體展示進(jìn)程所有線程蚊惯、內(nèi)存愿卸、GC 等情況
dashboard    -- 查看發(fā)現(xiàn)cpu高 不是GC引起的,占用CPU較多的線程只有一個(gè)
thread -n 6    -- 查看最繁忙的線程在執(zhí)行的線程堆棧信息截型,然后可以直接定位具體代碼行

在這個(gè)案例中趴荸,我們通過 Arthas 工具排查了高 CPU 的問題:

  • 首先,通過 dashboard + thread 命令宦焦,基本可以在幾秒鐘內(nèi)一鍵定位問題发钝,找出消耗 CPU 最多的線程和方法棧顿涣;
  • 然后,直接 jad 反編譯相關(guān)代碼酝豪,來確認(rèn)根因涛碑;
  • 此外,如果調(diào)用入?yún)⒉幻鞔_的話孵淘,可以使用 watch 觀察方法入?yún)⑵颜希⒏鶕?jù)方法執(zhí)行時(shí)間來過濾慢請(qǐng)求的入?yún)ⅰ?/li>

8.2 TPS過低問題

現(xiàn)象描述:新上線一個(gè)高并發(fā)的復(fù)雜業(yè)務(wù)接口,壓測的時(shí)候發(fā)現(xiàn)TPS只有50夺英,明顯是太低了,需要找出耗時(shí)較長的地方加以優(yōu)化滋捶。

trace xxx.DiscountCXOpenServiceImpl aaaRespCXDTOList  '#cost > 100' -n 1
由于trace命令只會(huì)匹配到的函數(shù)里的子調(diào)用痛悯,并不會(huì)向下trace多層,而這個(gè)業(yè)務(wù)接口很復(fù)雜重窟,所以一層層找下去的話载萌,太過于麻煩,所以用profiler 生成應(yīng)用熱點(diǎn)的火焰圖來查找比較好巡扇,

profiler start --event alloc
//等待10s
profiler stop --file /app/deploy/logs/profiler.svg
image.png

從上面的圖中可以看出最終耗時(shí)比較久的竟然是 fastjson 的 parseArray方法扭仁,然后找到具體調(diào)用的地方后,
發(fā)現(xiàn)是因?yàn)閮?nèi)部緩存的原因厅翔,由于內(nèi)部緩存用的公共方法乖坠,value為Stiring,所以每次getValue后刀闷,都需要parseArray 轉(zhuǎn)化為List<Bean> 熊泵,之所以使用內(nèi)部緩存就是因?yàn)関alue值太大,存redis時(shí)會(huì)造成網(wǎng)卡帶寬不夠甸昏,所以我們需要修改為自定義內(nèi)部緩存顽分,這樣就可以避免 parseArray 方法,從而提高性能了施蜜。
private static ConcurrentHashMap<String, ConcurrentHashMap> cache = new ConcurrentHashMap<>();

這里其實(shí)還有一個(gè)問題卒蘸,這種大對(duì)象頻繁反序列化除了影響性能,還會(huì)每次都生成新的對(duì)象翻默,導(dǎo)致在高并發(fā)下缸沃,內(nèi)存也飆升。

8.3 排查線程阻塞問題

  • 1修械、thread篩選所有阻塞狀態(tài)的線程和泌。

  • 2、根據(jù)線程名稱定位具體的業(yè)務(wù)模塊祠肥,再選中該業(yè)務(wù)中的一條線程查看堆棧信息武氓。

  • 3梯皿、根據(jù)線程堆棧信息定位導(dǎo)致阻塞的具體方法,再利用stack命令查看方法堆棧信息县恕。

  • 4东羹、利用jad工具反編譯源碼,分析業(yè)務(wù)邏輯代碼并改善忠烛。

8.4 排查死鎖問題

  • 利用Arthas來檢測死鎖特別簡單属提,只需要執(zhí)行一行命令thread -b即可。

8.5 排查方法執(zhí)行過慢問題

  • 1美尸、通過trace命令排查方法執(zhí)行速度冤议,trace xx類 xx方法 '#cost>50ms',觀測執(zhí)行時(shí)間大于50ms的該方法的調(diào)用信息师坎。

  • 2恕酸、可以結(jié)合正則表達(dá)式,同時(shí)排查多個(gè)類胯陋、多個(gè)方法蕊温,trace -E ClassA|ClassB method1|method2|method3。

8.6 動(dòng)態(tài)修改線上代碼

上線之后遏乔,發(fā)現(xiàn)代碼有一處小地方存在邏輯錯(cuò)誤需要更改义矛,可以直接線上修改,而不用重啟盟萨。

  • 1凉翻、通過jad將要修改的類反編譯為.java文件,輸出到指定目錄捻激。
  • 2噪矛、本地糾正.java文件后,通過mc命令重新編譯.java文件铺罢。
  • 4艇挨、通過retransform命令將剛編譯的.class文件再次加載到JVM中。
    這種已經(jīng)很少使用了韭赘,僅限于不能重啟的情況下缩滨,通常還是直接發(fā)版解決的。

參考文章:學(xué)會(huì)Arthas泉瞻,讓你3年經(jīng)驗(yàn)掌握5年功力脉漏!

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個(gè)濱河市袖牙,隨后出現(xiàn)的幾起案子侧巨,更是在濱河造成了極大的恐慌,老刑警劉巖鞭达,帶你破解...
    沈念sama閱讀 218,546評(píng)論 6 507
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件司忱,死亡現(xiàn)場離奇詭異皇忿,居然都是意外死亡,警方通過查閱死者的電腦和手機(jī)坦仍,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,224評(píng)論 3 395
  • 文/潘曉璐 我一進(jìn)店門鳍烁,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人繁扎,你說我怎么就攤上這事幔荒。” “怎么了梳玫?”我有些...
    開封第一講書人閱讀 164,911評(píng)論 0 354
  • 文/不壞的土叔 我叫張陵爹梁,是天一觀的道長。 經(jīng)常有香客問我提澎,道長姚垃,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,737評(píng)論 1 294
  • 正文 為了忘掉前任虱朵,我火速辦了婚禮莉炉,結(jié)果婚禮上钓账,老公的妹妹穿的比我還像新娘碴犬。我一直安慰自己,他們只是感情好梆暮,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,753評(píng)論 6 392
  • 文/花漫 我一把揭開白布服协。 她就那樣靜靜地躺著,像睡著了一般啦粹。 火紅的嫁衣襯著肌膚如雪偿荷。 梳的紋絲不亂的頭發(fā)上,一...
    開封第一講書人閱讀 51,598評(píng)論 1 305
  • 那天唠椭,我揣著相機(jī)與錄音跳纳,去河邊找鬼。 笑死贪嫂,一個(gè)胖子當(dāng)著我的面吹牛寺庄,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播力崇,決...
    沈念sama閱讀 40,338評(píng)論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼斗塘,長吁一口氣:“原來是場噩夢啊……” “哼!你這毒婦竟也來了亮靴?” 一聲冷哼從身側(cè)響起馍盟,我...
    開封第一講書人閱讀 39,249評(píng)論 0 276
  • 序言:老撾萬榮一對(duì)情侶失蹤,失蹤者是張志新(化名)和其女友劉穎茧吊,沒想到半個(gè)月后贞岭,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體八毯,經(jīng)...
    沈念sama閱讀 45,696評(píng)論 1 314
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,888評(píng)論 3 336
  • 正文 我和宋清朗相戀三年曹步,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了宪彩。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點(diǎn)故事閱讀 40,013評(píng)論 1 348
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡讲婚,死狀恐怖尿孔,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情筹麸,我是刑警寧澤活合,帶...
    沈念sama閱讀 35,731評(píng)論 5 346
  • 正文 年R本政府宣布,位于F島的核電站物赶,受9級(jí)特大地震影響白指,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜酵紫,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,348評(píng)論 3 330
  • 文/蒙蒙 一告嘲、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧奖地,春花似錦橄唬、人聲如沸。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,929評(píng)論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽。三九已至犬庇,卻和暖如春僧界,著一層夾襖步出監(jiān)牢的瞬間,已是汗流浹背臭挽。 一陣腳步聲響...
    開封第一講書人閱讀 33,048評(píng)論 1 270
  • 我被黑心中介騙來泰國打工捂襟, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留,地道東北人欢峰。 一個(gè)月前我還...
    沈念sama閱讀 48,203評(píng)論 3 370
  • 正文 我出身青樓葬荷,卻偏偏與公主長得像,于是被迫代替她去往敵國和親赤赊。 傳聞我的和親對(duì)象是個(gè)殘疾皇子闯狱,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,960評(píng)論 2 355

推薦閱讀更多精彩內(nèi)容