看到標題是不是很多人在想是不是標題黨了,是也不是👻~,請聽我細細道來~
我們的應用程式碼是用Java寫的,因此使用的火焰圖工具是Arthas,下面的分析也是基於此。
Arthas火焰圖使用
官方文件:
https://arthas.aliyun.com/doc/profiler.html
啟動火焰圖分析
$ profiler start Started [cpu] profiling
停止
$ profiler stop --format flamegraph profiler output file: /tmp/test/arthas-output/20211207-111550.html OK
如上所示預設會生成一個html的火焰圖檔案,指定輸出格式相關可參考官方文件。
火焰圖示例
火焰圖橫軸代表CPU的佔用時間,橫軸越寬代表CPU佔用越多,滑鼠移動上去也可以看到這個方法究竟佔用了多少CPU。
縱軸代表呼叫棧,火焰越高代表呼叫棧越深。
其中綠色部分代表Java程式碼,黃色部分代表JVM C++程式碼,橙色部分代表核心態C語言程式碼,紅色代表使用者態C語言程式碼。
如何分析火焰圖(附實戰)
事情是這樣的,我們的業務簡單來說就是監聽發貨訊息後執行一系列操作,分自動和批次兩種方式,批次的大使用者進行業務操作時,會同時有幾萬單、十幾萬單的產生,相當於大促時的流量了,因此cpu佔用總是有尖刺,有時單機甚至能到80+%。而且日常流量時感覺cpu佔用和流量資料相比也有些偏高,因此決定使用火焰圖分析下。
從上往下看
下面採用兩個在最佳化過程中比較典型的兩個案例。
案例一
火焰圖分析最簡單的方式就是找大平頂,如果一個方法佔用比較耗時、呼叫次數很多,那麼他的橫軸一定是比較寬的,體現到火焰圖上就是一個大平頂。
圖中紅框是業務程式碼的執行,其中藍框是初步定位到的耗時操作,點開後可以看到左側是sentinel取樣CPU佔用,佔用總CPU3%~4%,這部分應該是不會隨流量上升而升高的, 這次就先沒有動這塊。第二塊是在metaq的消費者程式碼裡執行的,因此重點關注,因為我們的應用是訊息驅動的,接受tp的發貨訊息後進行對應的操作,metaq流量升高,這部分對應的操作大機率也是會隨之升高的。
佔總CPU佔用達到了驚人的9.3%。
點開後可以看到是脫敏工具,其對效能的影響幾乎和發貨訊息齊平了,排查後發現是我們部門內部使用的鏈路採集工具,在採集metaq訊息時會對訊息進行脫敏處理,脫敏工具會對姓名、郵箱、手機號等分別進行正則匹配,而我們接收的交易訊息中是包含整個訂單資訊的,這個物件是很大的(包含擴充套件欄位等諸多資訊),對其使用正則進行脫敏工作量巨大。正常情況下使用此工具採集線上流量對效能影響不是很大,但是在我們的場景影響有點出乎意料......
由於我們平時基本不會在鏈路圖上關注訊息的內容,一般都是用來看HSF鏈路,因此直接把dp對metaq的採集關閉了。
案例二
使用全域性搜尋後居然佔用了將近6%的CPU,這可是日常的流量下擷取的火焰圖,系統流量升高時佔用比例會更大。
點開後可以看到是進行HSF呼叫的時候,獲取Java呼叫棧比較耗時,之前寫程式碼的時候懷疑過獲取呼叫棧會比較耗效能,但沒想到居然比一次HSF呼叫本身的耗時都大了。這個地方之前是爲了獲取呼叫來源,列印到日誌中方便排查問題的(歷史程式碼),後續將HSF的呼叫日誌改成了透過HSF Filter的方式,去掉了獲取呼叫棧的邏輯。
其實案例二我一開始不是從上往下看定位到的,因為呼叫HSF的地方不止一個,每個耗時其實也不長,整體看的話從上往下還是比較難發現的。
從下往上看
案例二
如果從上往下看效果不明顯,可以從我們系統主要流量入口處進行分析,從下面入口一步步往上點,也可以發現問題,帶著懷疑的態度來找,上述的案例二我一開始並沒有注意到上方的問題,我是一步步從訊息入口看,然後點到上面發現的這個呼叫消耗居然比HSF多的。
可以看到這個呼叫不是集中在一個地方的,細看每個地方都有呼叫,所以整體對效能的影響才那麼大。
全域性搜尋後可以看到到處都有呼叫(圖示紫色部分)。
從下往上找更適合細化的時候,專門對某個鏈路進行分析最佳化。
最佳化效果
下面來讓我們計算一下資料,來看看樓主是不是標題黨了。
整體大致最佳化了5~6%左右(7月份的時候,機器數量是30臺,8月縮容到了27臺),取5%,其中系統CPU佔用在6.5%左右,從日常流量上來看,使用者態cpu從26%到21%,下降19%+,考慮縮容的關係,20%的最佳化大抵是有的👻。
由於這是日常流量的最佳化結果,大促流量突增時,系統負載降低應該會更明顯,最佳化後大使用者批次操作時瞬時流量也基本不會有機器cpu佔用超過60%了。
後續雙十一壓測也會繼續關注最佳化,流量上升後更多問題可能就會暴露出來。