引言
本文主要介紹火焰圖及使用技巧，學習如何使用火焰圖快速定位軟體的性能卡點，
結合最佳實踐實戰案例，幫助讀者加深刻的理解火焰圖構造及原理，理解 CPU 耗時，定位性能瓶頸，
背景
當前現狀
假設沒有火焰圖，你是怎么調優程式代碼的呢？讓我們來捋一下，
1. 功能開關法
想當年我剛作業，還是一個技術小白時，排查問題只能靠玄學，大致能猜出問題可能是由某個功能代碼導致的，此時的排查手段就是洗掉多余的功能代碼，然后再運行查看 CPU 消耗，確定問題，（至今我作業時還會發現一些老人使用如此方法除錯性能，）
public void demo() {
if (關閉1) {
// 功能1
handle1();
}
if (關閉2) {
// 功能2
handle2();
}
if (打開3) {
// 功能3
handle3();
}
// 功能4
handle4();
}
此法全靠“經驗”和“運氣”，而且改動了代碼結構，假設這是一個已經通過測驗的集成區代碼，此時需要修改代碼功能來除錯程式是非常危險的一件事，當然有 Git 倉庫可以“一鍵還原”，但是，是人操作，總歸會有失手的時候，且定位效率太低
2. StopWatch 埋點法
當程式出現性能問題時，且不確定是哪一段代碼導致耗時，可以借助方法耗時來判斷，此時我們只要在呼叫方法前后追加執行所需耗時日志，即可判定到底是哪個方法最耗時，
public void demo() {
Stopwatch stopwatch = Stopwatch.createStarted();
handle1();
log.info("method handle1 cost: {} ms",
stopwatch.elapsed(TimeUnit.MILLISECONDS));
handle2();
log.info("method handle2 cost: {} ms",
stopwatch.elapsed(TimeUnit.MILLISECONDS));
handle3();
log.info("method handle3 cost: {} ms",
stopwatch.elapsed(TimeUnit.MILLISECONDS));
handle4();
log.info("method handle4 cost: {} ms",
stopwatch.stop().elapsed(TimeUnit.MILLISECONDS));
}
此法較上一個方法的優勢是，不改變代碼的邏輯情況下，只是增強了一些觀測點位，由方法的耗時來定位性能瓶頸，但是，假設方法的處理呼叫堆疊很深，就不得不在子方法中再次埋點，此時判定流程即為：埋點 -> 發版 -> 定位 -> 埋點 -> 發版 -> 定位 -> .......且本質上也是改了代碼，就有出錯的可能， 心累，不高效！
3. TOP 命令定位熱執行緒
一般企業的軟體服務都是部署在 Linux 作業系統上，有經驗的老手排查性能最方便的辦法就是 top 定位，
top -p pid -H
明顯看到，pid 103 消耗了 40%的 CPU, 找到對應的 stack 執行緒資訊如下（忽略查找辦法，我假設你已經會了：））：
此時可以得出結論，當前最耗 CPU 的執行緒是寫入磁盤檔案，追查代碼最侄訓定位到是因為在高并發場景下打了大量的 INFO 日志，導致磁盤寫入成為瓶頸，
總結：TOP 命令對于找 CPU 性能瓶頸時很有效的，但是存在如下幾個問題：
- 排名最前的一定是當時最消耗 CPU 的，但不一定是程式性能的誘因，例如因某個 BUG 導致列印了大量 ERROR 日志，最終 LOG 到磁盤是最消耗 CPU的，但罪魁禍首不是它，
- TOP 注定使你只會關注最高的，等你修復最耗 CPU 的問題后，往往還會遇到別的程式問題導致 CPU 偏高，即一次只能看到一個問題，看不到全貌，
- 文本的表現力非常有限：首先你得對 Linux 及 JVM 命令非常熟悉，其次文本對兩個及以上值做關聯性分析時，就捉襟見肘了，此時就迫切的需要另一種分析工具——圖，
什么是火焰圖
火焰圖（Flame Graphs），因其形似火焰而得名，
如上就是一個典型的火焰圖，它由各種大小/顏色的方塊組成，每個方塊內部還標識了文字，整個圖片頂部凹凸不平，形似一簇簇“火苗”，因此得名火焰圖，
火焰圖是 SVG 生成，因此可以與用戶互動，滑鼠懸浮在某個方塊時，會詳細展示內部文字，點擊后，即會以當前被點擊方塊為底向上展開，
特征
使用火焰圖分析之前，我們得首先了解火焰圖的基本構造
- 每一列代表一個呼叫堆疊，每一格代表一個被呼叫函式
- 方塊上的字符標識呼叫方法，數字表示當前采樣出現次數
- Y 軸表示呼叫堆疊深度，X 軸將多個呼叫堆疊歸并，并首字母排序展示
- X 軸寬度表示采樣資料中出現頻次，即寬度越大，導致性能瓶頸的原因可能就越大（注意：是可能，不是確定）
- 顏色沒什么意義，隨機分配（可能創始人想讓你看起來更像一個火焰，，）
火焰圖可以做什么
那此時你已經知道了火焰圖，如何定位軟體問題呢？我們需要一套尋找性能瓶頸的方法論，
可以明確的是 CPU 消耗高的口徑
CPU 消耗高的口徑 = 呼叫堆疊出現頻率最高的一定是吃 CPU 的
如上我們已經知道了火焰圖的構造，及“物料”含義，此時我們的關注點應該在方形的寬度上，方形的寬度大小代表了該呼叫堆疊在整個抽樣歷史中出現的次數，次數意味著頻率，即出現次數越多的即可能最消耗 CPU，
但只關注最長的是沒用的，如底部的 root 和中部的方塊都很寬，只能說明這些方法是“入口方法”，即每次發起呼叫都會經過的方法，
我們更應該關注火焰山頂部的"平頂山"（plateaus）出現的次數多，即沒有子呼叫，抽樣出現的頻率高，說明執行方法的時間較長，或者執行頻率太高（如長輪詢），即CPU 大部分執行都分配給了“平頂山”，它才是性能瓶頸的根因，
總結方法論：火焰圖看“平頂山”，山頂的函式可能存在性能問題！
最佳實踐
實踐是檢驗真理的唯一標準！下面我將以一個小的 Demo 來展示如何定位程式性能問題，加深對火焰圖使用的理解，
Demo 程式如下：
public class Demo {
public static void main(String[] args) throws InterruptedException {
ExecutorService executorService = Executors.newFixedThreadPool(20);
while (true) {
executorService.submit(Demo::handle1);
executorService.submit(Demo::handle2);
executorService.submit(Demo::handle3);
executorService.submit(Demo::handle4);
}
}
@SneakyThrows
private static void handle4() {
Thread.sleep(1000);
}
@SneakyThrows
private static void handle2() {
Thread.sleep(50);
}
@SneakyThrows
private static void handle3() {
Thread.sleep(100);
}
@SneakyThrows
private static void handle1() {
Thread.sleep(50);
}
}
代碼很簡單，當然現實中也不會這么寫，主要是配合演出，，
主要是開了一個執行緒池，且分別執行四個 task，不同的 task 耗時不一致，此時我們的性能瓶頸在 handle4 這個任務上，在知道結論的前提下，我們比較看火焰圖得出答案的是否符合預期！
1. JVM堆疊資訊拉取
當前我是在自己的 Mac 上運行的程式，idea 執行這一段程式非常便捷，那如何獲取當前運行 main 函式的 PID？
此時需要用到 TOP 命令，上面是個 while 死回圈，很明顯吃 CPU最厲害，只要找到歸屬 Java 執行緒的最高一個 PID 即為所求，
很明顯得到 COMMAND = java 最高的 PID = 20552
此時執行如下命令獲取堆疊資訊，并寫入 tmp.txt 檔案
jstack -l 20552 > tmp.txt
2. 生成火焰圖
生成火焰圖的工具有很多，我一般會借助 FastThread，在線分析堆疊，非常方便，同時支持生成火焰圖，方便我們定位問題
打開官網首頁，選擇剛剛 dump 的堆疊檔案，點擊 Analyze，此時只需要等待網站分析好后（正常 3~5 s），即可查看火焰圖
fastThread 網站分析報告非常豐富，一般的問題我們直接通過它給出的結論基本能定位到問題了，本文暫且無需關注，感興趣的話，后續我會分享，直接拉到 Flame Graph 子標題處
此時明顯能看出4個“平頂山”，且 com.Demo.handle4 寬度最大，com.Demo.handle3 次之，符合預期！
原理剖析
基于上述小 Demo ，我們深入理解下火焰圖的生成原理，
舉個例子，便于你理解，假設我們要觀測一個人在忙些什么，哪些事最占用他的時間，會怎么做？
從時間維度的話，且不考慮成本的話，我肯定安排一個監控攝像頭，全天候 24h，360度監控他，然后再安排人員，逐幀排查，并匯總他所做的事，得出：睡覺 8h，作業8h，玩手機 4h，吃飯2h，其它2h，從而得出結論：睡覺占用他時間最多，
由上可以總結一套分析流程：
記錄（監控）-> 分析&歸并（逐幀排查） -> Top N -> 得出結論
帶著流程去看我們應該如何排查 CPU 在執行中，哪些事（行程/執行緒）最占用它的時間呢？
簡單粗暴的方法是每時每刻都記錄執行的方法堆疊，再匯總歸并，得出最耗時的方法堆疊在哪，此法的問題在于
- 資料量大
- 時間長
其實只要采樣去觀測 CPU 在干什么就好了，這是一個概率學問題，如果 CPU 因為執行某個方法耗時，大概率采樣下來，得到的歸并結果也是最多的，雖然有誤差，但是多次統計下，差不了多少的，
同理，dump 下的堆疊，查看大多數執行緒在干什么，依據堆疊內每個方法出現的頻率聚合，出現的頻次最多的就是當前 CPU 分配執行最多的方法，
"pool-1-thread-18" #28 prio=5 os_prio=31 tid=0x00007f9a8d4c0000 nid=0x8d03 sleeping[0x000000030be59000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.Demo.handle2(Demo.java:31)
at com.Demo$$Lambda$2/1277181601.run(Unknown Source)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- <0x00000006c6921ac0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
至于我們的 jstack 資訊如何被處理成火焰圖的格式，社區已經為常見的 dump 格式都提供了工具，stackcollapse-jstack.pl 處理 jstack 輸出，
Example input:
"MyProg" #273 daemon prio=9 os_prio=0 tid=0x00007f273c038800 nid=0xe3c runnable [0x00007f28a30f2000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
...
at java.lang.Thread.run(Thread.java:744)
Example output:
MyProg;java.lang.Thread.run;java.net.SocketInputStream.read;java.net.SocketInputStream.socketRead0 1
總結&展望
火焰圖的介紹到此結束，相信你又多了一種排查問題的手段！
存在即合理，工具之開發重要性而言不必多說，我始終持包容態度面對新事物，它確確實實解決了某些痛點而脫穎而出的，
后續我會介紹更多排查問題的手段，如果你喜歡本文風格，請關注或留言，歡迎討論！
轉載請註明出處，本文鏈接：https://www.uj5u.com/houduan/503347.html
標籤：其他
上一篇：基本運算子