又一款效能監控利器——火焰圖

民工哥發表於2021-12-01

前言

工具的進化一直是人類生產力進步的標誌,合理使用工具能大大提高我們的工作效率,遇到問題時,合理使用工具更能加快問題排查的進度。這也是我為什麼非常喜歡 shell 的原因,它豐富的命令列工具集加管道特性處理起文字資料集來真的精準而優雅,讓人迷醉。

但很多時候文字的表現力非常有限,可以說匱乏,表達絕對值時,自然是無往不利,但在展示相對值時,就有些捉襟見肘了,就更不用說多維資料了。

我們用 shell 可以非常快速地查詢出文字內的累加值、最大值等,但一遇到兩組值的相關性分析時,就束手無策了。這個時候,就需要使用另一種分析工具 – 圖了,如散點圖就能很清晰地展示相關性。

今天就準備介紹一種圖,火焰圖,之前組內大神分享過它的使用辦法,但我之後很久都沒有用過,以至於對它沒有什麼深刻印象,最近排查我們 Java 應用負載問題時試用了一下,這才對它的用途有了點心得。

介紹

引子

在排查效能問題時,我們通常會把執行緒棧 dump 出來,然後使用

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

類似的 shell 語句,檢視大多數執行緒棧都在幹什麼。而由執行緒棧的出現頻率,來推斷 JVM 內耗時最多的呼叫。

至於其原理,設想廣場上有一個大螢幕在不停地播放各種廣告。如果我們隨機對大螢幕拍照,次數多了,統計照片中各個廣告出現的頻率,基本可以得出每個廣告的播放時長佔比了。

而我們應用的資源就像大螢幕,每次呼叫就像是播放一次廣告,統計 dump 出的執行緒棧出現比例,也就基本能看出執行緒棧的耗時佔比,雖然有誤差,但是多次統計下應該差不了多少。這也就是為什麼有些家長每次進孩子房間都發現孩子在看系統桌面後以為孩子平時喜歡對著桌面發呆的原因。:)

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 挺費事的,另外如果我想檢視自棧頂第二個棧的最多呼叫,即使修改了 shell 命令,結果也不直觀。

產生這個問題的主要原因是,我們的執行緒棧是有呼叫關係的,即我們需要考慮執行緒棧的 呼叫鏈 和 出現頻率 兩個維度,而單一的文字表現這兩種維度比較困難,所以,著名效能分析大師 brendan gregg 就提出了火焰圖。

介紹

火焰圖,因其形似火焰而得名,其開原始碼地址:

https://github.com/brendangregg/FlameGraph

它是一種 svg 可互動式圖形,我們通過點選和滑鼠指向可以展示出更多的資訊。下圖就是一個典型的火焰圖,從結構上,它是由多個大小和顏色各異的方塊構成,每個方塊上都有字元,它們底部連線在一塊,組成火焰的基底,頂部分出許多”小火苗”。

image.png

當我們點選方塊時,圖片會從我們點選的方塊為基底向上展開,而我們滑鼠指向方塊時,會展示出方塊的詳細說明。

特性

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

  • 由底部到頂部可以追溯一個唯一的呼叫鏈,下面的方塊是上面方塊的父呼叫。
  • 同一父呼叫的方塊從左到右以字母序排列。
  • 方塊上的字元表示一個呼叫名稱,括號內是火焰圖指向的呼叫在火焰圖中出現的次數和這個方塊佔最底層方塊的寬度百分比。
  • 方塊的顏色沒有實際意義,相鄰方塊的顏色差只為了便於檢視。
分析

那麼,給我們一張火焰圖,我們怎麼能看出系統哪裡有問題呢?

由上文中的火焰圖特性特性,檢視火焰圖時,我們最主要的關注點要放在方塊的寬度上,因為寬度代表了呼叫棧在全域性出現的次數,次數代表著出現頻率,而頻率也就可以說明耗時。

但是觀察火焰圖底部或中部方塊的寬度佔比意義不大,如上面的火焰圖,中部的 do_redirections 函式寬度是 24.87%,也就是說它耗用了整個應用近四分之一的時間,但是真正消耗時間的並不是 do_redirections 函式,而是 do_redirections 內部又呼叫的其他函式,而它的子呼叫分為了很多個,每個呼叫的耗時並沒有異常。

我們更應該關注的是火焰圖頂部的一些 “平頂山”,頂部說明它沒有子呼叫,方塊寬說明它耗時長,長時間 hang 住,或者被非常頻率地呼叫,這種方塊指向的呼叫才是效能問題的罪魁禍首。

找到了異常呼叫,直接優化它,或者再根據火焰圖的呼叫鏈層層向下,找到我們的業務程式碼進行優化,也就大功告成。

應用場景

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

  • 程式碼迴圈分析:如果程式碼中有很大的迴圈或死迴圈程式碼,那麼從火焰圖的頂部或接近項部的地方會有很明顯的”平頂”,表示程式碼頻繁地在某個執行緒棧上下切換。但需要注意的是,如果迴圈的總耗時不長,在火焰圖上不會很明顯。
  • IO 瓶頸/鎖分析:在我們的應用程式碼中,我們的呼叫普遍都是同步的,也就是說在進行網路呼叫、檔案 I/O 操作或未成功獲得鎖時,執行緒會停留在某個呼叫上等待 I/O 響應或鎖,如果這個等待非常耗時,會導致執行緒在某個呼叫上一直 hang 住,這在火焰圖上表現得會非常清晰。與此相對的是,我們應用執行緒構成的火焰圖無法準確地表達 CPU 的消耗,因為應用執行緒內沒有系統的呼叫棧,在應用執行緒棧 hang 住時,CPU 可能去做其他事了,導致我們看到耗時很長,而 CPU 卻很閒。
  • 火焰圖倒置分析全域性程式碼:火焰圖倒置有時也會很實用,如果我們的程式碼 N 個不同的分支都呼叫某一方法,倒置後,所有棧頂相同的呼叫被合併在一塊,我們就能看出這個方法的總耗時,也就很容易評估出優化這個方法的收益。

實現

既然火焰圖這麼強大,那麼我們該怎麼實現呢?

生成工具

brendan gregg 大神已經把生成火焰圖的方法用 perl 實現了,開原始碼就在上文的 Github 倉庫中,根目錄下的 flamegraph.pl 檔案就是可執行的 perl 檔案了。

這個命令還可以傳入各種引數,支援我們修改火焰圖的顏色、大小等。

但 flamegraph.pl 只能處理特定格式的檔案,像:

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

前面是呼叫鏈,每個呼叫之間用 ; 隔開,每行後面的數字是呼叫棧出現的次數。

如上面的資料,用 flamegraph.pl 生成的火焰圖如下圖:

資料準備

至於我們的 jstack 資訊如何被處理成上面的格式,大神則為常見的 dump 格式都提供了工具,像 stackcollapse-perf.pl可以處理 perf 命令的輸出,stackcollapse-jstack.pl 處理 jstack 輸出,stackcollapse-gdb.pl 處理 gdb 輸出的棧等。

也可以用 shell 簡單地實現一下 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}'

小結

火焰圖總結完了,以後再遇到效能問題又多了一種應對方式。

做開發越久,越能感受得到工具的重要性,所以我準備加一個專題來專門介紹我使用的各種工具。當然,這也就更需要我更多地瞭解、使用和總結新的工具了。

來源:https://zhenbianshu.github.io

相關文章