超牛逼的性能調(diào)優(yōu)利器 — 火焰圖

前言

工具的進(jìn)化一直是人類生產(chǎn)力進(jìn)步的標(biāo)志翠语,合理使用工具能大大提高我們的工作效率的止,遇到問題時,合理使用工具更能加快問題排查的進(jìn)度骗污。這也是我為什么非常喜歡 shell 的原因崇猫,它豐富的命令行工具集加管道特性處理起文本數(shù)據(jù)集來真的精準(zhǔn)而優(yōu)雅,讓人迷醉需忿。

但很多時候文本的表現(xiàn)力非常有限诅炉,可以說匱乏,表達(dá)絕對值時屋厘,自然是無往不利涕烧,但在展示相對值時,就有些捉襟見肘了汗洒,就更不用說多維數(shù)據(jù)了议纯。

我們用 shell 可以非常快速地查詢出文本內(nèi)的累加值溢谤、最大值等瞻凤,但一遇到兩組值的相關(guān)性分析時憨攒,就束手無策了。這個時候阀参,就需要使用另一種分析工具 – 圖了浓恶,如散點(diǎn)圖就能很清晰地展示相關(guān)性。

今天就準(zhǔn)備介紹一種圖结笨,火焰圖包晰,之前組內(nèi)大神分享過它的使用辦法,但我之后很久都沒有用過炕吸,以至于對它沒有什么深刻印象伐憾,最近排查我們 Java 應(yīng)用負(fù)載問題時試用了一下,這才對它的用途有了點(diǎn)心得赫模。

介紹

引子

在排查性能問題時树肃,我們通常會把線程棧 dump 出來,然后使用

grep --no-group-separator -A 1 java.lang.Thread.State jstack.log | awk 'NR%2==0' | sort | uniq -c | sort -nr 

類似的 shell 語句瀑罗,查看大多數(shù)線程棧都在干什么胸嘴。而由線程棧的出現(xiàn)頻率,來推斷 JVM 內(nèi)耗時最多的調(diào)用斩祭。

至于其原理劣像,設(shè)想廣場上有一個大屏幕在不停地播放各種廣告。如果我們隨機(jī)對大屏幕拍照摧玫,次數(shù)多了耳奕,統(tǒng)計(jì)照片中各個廣告出現(xiàn)的頻率,基本可以得出每個廣告的播放時長占比了诬像。

而我們應(yīng)用的資源就像大屏幕屋群,每次調(diào)用就像是播放一次廣告,統(tǒng)計(jì) dump 出的線程棧出現(xiàn)比例坏挠,也就基本能看出線程棧的耗時占比芍躏,雖然有誤差,但是多次統(tǒng)計(jì)下應(yīng)該差不了多少降狠。這也就是為什么有些家長每次進(jìn)孩子房間都發(fā)現(xiàn)孩子在看系統(tǒng)桌面后以為孩子平時喜歡對著桌面發(fā)呆的原因对竣。:)

2444  at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1200)
1587  at sun.misc.Unsafe.park(Native Method)
795  at java.security.Provider.getService(Provider.java:1035)
293  at java.lang.Object.wait(Native Method)
292  at java.lang.Thread.sleep(Native Method)
 73  at org.apache.logging.log4j.core.layout.TextEncoderHelper.copyDataToDestination(TextEncoderHelper.java:61)
 71  at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
 70  at java.lang.Class.forName0(Native Method)
 54  at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.checkRollover(RollingFileManager.java:217)

但是這樣有些問題,首先寫 shell 挺費(fèi)事的喊熟,另外如果我想查看自棧頂?shù)诙€棧的最多調(diào)用柏肪,即使修改了 shell 命令,結(jié)果也不直觀芥牌。

產(chǎn)生這個問題的主要原因是烦味,我們的線程棧是有調(diào)用關(guān)系的,即我們需要考慮線程棧的 調(diào)用鏈 和 出現(xiàn)頻率 兩個維度,而單一的文本表現(xiàn)這兩種維度比較困難谬俄,所以柏靶,著名性能分析大師 brendan gregg 就提出了火焰圖。

介紹

火焰圖溃论,因其形似火焰而得名屎蜓,其開源代碼地址:

https://github.com/brendangregg/FlameGraph

它是一種 svg 可交互式圖形,我們通過點(diǎn)擊和鼠標(biāo)指向可以展示出更多的信息钥勋。下圖就是一個典型的火焰圖炬转,從結(jié)構(gòu)上,它是由多個大小和顏色各異的方塊構(gòu)成算灸,每個方塊上都有字符扼劈,它們底部連接在一塊,組成火焰的基底菲驴,頂部分出許多”小火苗”荐吵。

image.png

當(dāng)我們點(diǎn)擊方塊時,圖片會從我們點(diǎn)擊的方塊為基底向上展開赊瞬,而我們鼠標(biāo)指向方塊時先煎,會展示出方塊的詳細(xì)說明。

特性

介紹火焰圖的分析前巧涧,我們要首先說明它的特性:

  • 由底部到頂部可以追溯一個唯一的調(diào)用鏈薯蝎,下面的方塊是上面方塊的父調(diào)用。
  • 同一父調(diào)用的方塊從左到右以字母序排列褒侧。
  • 方塊上的字符表示一個調(diào)用名稱良风,括號內(nèi)是火焰圖指向的調(diào)用在火焰圖中出現(xiàn)的次數(shù)和這個方塊占最底層方塊的寬度百分比。
  • 方塊的顏色沒有實(shí)際意義闷供,相鄰方塊的顏色差只為了便于查看。
分析

那么统诺,給我們一張火焰圖歪脏,我們怎么能看出系統(tǒng)哪里有問題呢?

由上文中的火焰圖特性特性粮呢,查看火焰圖時婿失,我們最主要的關(guān)注點(diǎn)要放在方塊的寬度上,因?yàn)閷挾却砹苏{(diào)用棧在全局出現(xiàn)的次數(shù)啄寡,次數(shù)代表著出現(xiàn)頻率豪硅,而頻率也就可以說明耗時。

但是觀察火焰圖底部或中部方塊的寬度占比意義不大挺物,如上面的火焰圖懒浮,中部的 do_redirections 函數(shù)寬度是 24.87%,也就是說它耗用了整個應(yīng)用近四分之一的時間,但是真正消耗時間的并不是 do_redirections 函數(shù)砚著,而是 do_redirections 內(nèi)部又調(diào)用的其他函數(shù)次伶,而它的子調(diào)用分為了很多個,每個調(diào)用的耗時并沒有異常稽穆。

我們更應(yīng)該關(guān)注的是火焰圖頂部的一些 “平頂山”冠王,頂部說明它沒有子調(diào)用,方塊寬說明它耗時長舌镶,長時間 hang 住柱彻,或者被非常頻率地調(diào)用,這種方塊指向的調(diào)用才是性能問題的罪魁禍?zhǔn)住?/p>

找到了異常調(diào)用餐胀,直接優(yōu)化它哟楷,或者再根據(jù)火焰圖的調(diào)用鏈層層向下,找到我們的業(yè)務(wù)代碼進(jìn)行優(yōu)化骂澄,也就大功告成吓蘑。

應(yīng)用場景

每種工具都有其適合的應(yīng)用場景,火焰圖則適合用在:

  • 代碼循環(huán)分析:如果代碼中有很大的循環(huán)或死循環(huán)代碼坟冲,那么從火焰圖的頂部或接近項(xiàng)部的地方會有很明顯的”平頂”磨镶,表示代碼頻繁地在某個線程棧上下切換。但需要注意的是健提,如果循環(huán)的總耗時不長琳猫,在火焰圖上不會很明顯。
  • IO 瓶頸/鎖分析:在我們的應(yīng)用代碼中私痹,我們的調(diào)用普遍都是同步的脐嫂,也就是說在進(jìn)行網(wǎng)絡(luò)調(diào)用、文件 I/O 操作或未成功獲得鎖時紊遵,線程會停留在某個調(diào)用上等待 I/O 響應(yīng)或鎖账千,如果這個等待非常耗時,會導(dǎo)致線程在某個調(diào)用上一直 hang 住暗膜,這在火焰圖上表現(xiàn)得會非常清晰匀奏。與此相對的是,我們應(yīng)用線程構(gòu)成的火焰圖無法準(zhǔn)確地表達(dá) CPU 的消耗学搜,因?yàn)閼?yīng)用線程內(nèi)沒有系統(tǒng)的調(diào)用棧娃善,在應(yīng)用線程棧 hang 住時,CPU 可能去做其他事了瑞佩,導(dǎo)致我們看到耗時很長聚磺,而 CPU 卻很閑。
  • 火焰圖倒置分析全局代碼:火焰圖倒置有時也會很實(shí)用炬丸,如果我們的代碼 N 個不同的分支都調(diào)用某一方法瘫寝,倒置后,所有棧頂相同的調(diào)用被合并在一塊,我們就能看出這個方法的總耗時矢沿,也就很容易評估出優(yōu)化這個方法的收益滥搭。

實(shí)現(xiàn)

既然火焰圖這么強(qiáng)大,那么我們該怎么實(shí)現(xiàn)呢捣鲸?

生成工具

brendan gregg 大神已經(jīng)把生成火焰圖的方法用 perl 實(shí)現(xiàn)了瑟匆,開源代碼就在上文的 Github 倉庫中,根目錄下的 flamegraph.pl 文件就是可執(zhí)行的 perl 文件了栽惶。

這個命令還可以傳入各種參數(shù)愁溜,支持我們修改火焰圖的顏色、大小等外厂。

但 flamegraph.pl 只能處理特定格式的文件冕象,像:

a;b;c 12
a;d 3
b;c 3
z;d 5
a;c;e 3

前面是調(diào)用鏈,每個調(diào)用之間用 ; 隔開汁蝶,每行后面的數(shù)字是調(diào)用棧出現(xiàn)的次數(shù)渐扮。

如上面的數(shù)據(jù),用 flamegraph.pl 生成的火焰圖如下圖:

image.png
數(shù)據(jù)準(zhǔn)備

至于我們的 jstack 信息如何被處理成上面的格式掖棉,大神則為常見的 dump 格式都提供了工具墓律,像 stackcollapse-perf.pl可以處理 perf 命令的輸出,stackcollapse-jstack.pl 處理 jstack 輸出幔亥,stackcollapse-gdb.pl 處理 gdb 輸出的棧等耻讽。

也可以用 shell 簡單地實(shí)現(xiàn)一下 jstack 的處理方式:

grep -v -P '.+prio=d+ os_prio=d+' | grep -v -E 'locked <' | awk '{if ($0==""){print $0}else{printf"%s;",$0}}' | sort | uniq -c | awk '{a=$1;$1="";print $0,a}'

小結(jié)

火焰圖總結(jié)完了,以后再遇到性能問題又多了一種應(yīng)對方式帕棉。

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末针肥,一起剝皮案震驚了整個濱河市,隨后出現(xiàn)的幾起案子香伴,更是在濱河造成了極大的恐慌慰枕,老刑警劉巖,帶你破解...
    沈念sama閱讀 218,122評論 6 505
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件即纲,死亡現(xiàn)場離奇詭異捺僻,居然都是意外死亡,警方通過查閱死者的電腦和手機(jī)崇裁,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,070評論 3 395
  • 文/潘曉璐 我一進(jìn)店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來束昵,“玉大人拔稳,你說我怎么就攤上這事∏鲁” “怎么了巴比?”我有些...
    開封第一講書人閱讀 164,491評論 0 354
  • 文/不壞的土叔 我叫張陵,是天一觀的道長。 經(jīng)常有香客問我轻绞,道長采记,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,636評論 1 293
  • 正文 為了忘掉前任政勃,我火速辦了婚禮唧龄,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘奸远。我一直安慰自己既棺,他們只是感情好,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,676評論 6 392
  • 文/花漫 我一把揭開白布懒叛。 她就那樣靜靜地躺著丸冕,像睡著了一般。 火紅的嫁衣襯著肌膚如雪薛窥。 梳的紋絲不亂的頭發(fā)上胖烛,一...
    開封第一講書人閱讀 51,541評論 1 305
  • 那天,我揣著相機(jī)與錄音诅迷,去河邊找鬼佩番。 笑死,一個胖子當(dāng)著我的面吹牛竟贯,可吹牛的內(nèi)容都是我干的答捕。 我是一名探鬼主播,決...
    沈念sama閱讀 40,292評論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼屑那,長吁一口氣:“原來是場噩夢啊……” “哼拱镐!你這毒婦竟也來了?” 一聲冷哼從身側(cè)響起持际,我...
    開封第一講書人閱讀 39,211評論 0 276
  • 序言:老撾萬榮一對情侶失蹤沃琅,失蹤者是張志新(化名)和其女友劉穎,沒想到半個月后蜘欲,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體益眉,經(jīng)...
    沈念sama閱讀 45,655評論 1 314
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,846評論 3 336
  • 正文 我和宋清朗相戀三年姥份,在試婚紗的時候發(fā)現(xiàn)自己被綠了郭脂。 大學(xué)時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點(diǎn)故事閱讀 39,965評論 1 348
  • 序言:一個原本活蹦亂跳的男人離奇死亡澈歉,死狀恐怖展鸡,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情埃难,我是刑警寧澤莹弊,帶...
    沈念sama閱讀 35,684評論 5 347
  • 正文 年R本政府宣布涤久,位于F島的核電站,受9級特大地震影響忍弛,放射性物質(zhì)發(fā)生泄漏响迂。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,295評論 3 329
  • 文/蒙蒙 一细疚、第九天 我趴在偏房一處隱蔽的房頂上張望蔗彤。 院中可真熱鬧,春花似錦惠昔、人聲如沸幕与。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,894評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽啦鸣。三九已至,卻和暖如春来氧,著一層夾襖步出監(jiān)牢的瞬間诫给,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 33,012評論 1 269
  • 我被黑心中介騙來泰國打工啦扬, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留中狂,地道東北人。 一個月前我還...
    沈念sama閱讀 48,126評論 3 370
  • 正文 我出身青樓扑毡,卻偏偏與公主長得像胃榕,于是被迫代替她去往敵國和親。 傳聞我的和親對象是個殘疾皇子瞄摊,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,914評論 2 355