使用Arthas火焰圖工具的Java應(yīng)用性能分析和優(yōu)化經(jīng)驗

以下文章來源于阿里云開發(fā)者，作者譽(yù)銘

導(dǎo)讀

分享作者在使用Arthas火焰圖工具進(jìn)行Java應(yīng)用性能分析和優(yōu)化的經(jīng)驗。

看到標(biāo)題是不是很多人在想是不是標(biāo)題黨了，是也不是~，請聽我細(xì)細(xì)道來~

我們的應(yīng)用代碼是用Java寫的，因此使用的火焰圖工具是Arthas，下面的分析也是基于此。

Arthas火焰圖使用

啟動火焰圖分析

$ profiler start
Started [cpu] profiling

停止

$ profiler stop --format flamegraph
profiler output file: /tmp/test/arthas-output/20211207-111550.html
OK

如上所示默認(rèn)會生成一個html的火焰圖文件，指定輸出格式相關(guān)可參考官方文檔。

火焰圖示例

火焰圖橫軸代表CPU的占用時間，橫軸越寬代表CPU占用越多，鼠標(biāo)移動上去也可以看到這個方法究竟占用了多少CPU。

縱軸代表調(diào)用棧，火焰越高代表調(diào)用棧越深。

其中綠色部分代表Java代碼，黃色部分代表JVM C++代碼，橙色部分代表內(nèi)核態(tài)C語言代碼，紅色代表用戶態(tài)C語言代碼。

如何分析火焰圖(附實戰(zhàn))

事情是這樣的，我們的業(yè)務(wù)簡單來說就是監(jiān)聽發(fā)貨消息后執(zhí)行一系列操作，分自動和批量兩種方式，批量的大用戶進(jìn)行業(yè)務(wù)操作時，會同時有幾萬單、十幾萬單的產(chǎn)生，相當(dāng)于大促時的流量了，因此cpu占用總是有尖刺，有時單機(jī)甚至能到80+%。而且日常流量時感覺cpu占用和流量數(shù)據(jù)相比也有些偏高，因此決定使用火焰圖分析下。

從上往下看

下面采用兩個在優(yōu)化過程中比較典型的兩個案例。

案例一

火焰圖分析最簡單的方式就是找大平頂，如果一個方法占用比較耗時、調(diào)用次數(shù)很多，那么他的橫軸一定是比較寬的，體現(xiàn)到火焰圖上就是一個大平頂。

圖中紅框是業(yè)務(wù)代碼的執(zhí)行，其中藍(lán)框是初步定位到的耗時操作，點開后可以看到左側(cè)是sentinel采樣CPU占用，占用總CPU3%~4%，這部分應(yīng)該是不會隨流量上升而升高的， 這次就先沒有動這塊。第二塊是在metaq的消費(fèi)者代碼里執(zhí)行的，因此重點關(guān)注，因為我們的應(yīng)用是消息驅(qū)動的，接受tp的發(fā)貨消息后進(jìn)行對應(yīng)的操作，metaq流量升高，這部分對應(yīng)的操作大概率也是會隨之升高的。

占總CPU占用達(dá)到了驚人的9.3%。 點開后可以看到是脫敏工具，其對性能的影響幾乎和發(fā)貨消息齊平了，排查后發(fā)現(xiàn)是我們部門內(nèi)部使用的鏈路采集工具，在采集metaq消息時會對消息進(jìn)行脫敏處理，脫敏工具會對姓名、郵箱、手機(jī)號等分別進(jìn)行正則匹配，而我們接收的交易消息中是包含整個訂單信息的，這個對象是很大的(包含擴(kuò)展字段等諸多信息)，對其使用正則進(jìn)行脫敏工作量巨大。正常情況下使用此工具采集線上流量對性能影響不是很大，但是在我們的場景影響有點出乎意料...... 由于我們平時基本不會在鏈路圖上關(guān)注消息的內(nèi)容，一般都是用來看HSF鏈路，因此直接把dp對metaq的采集關(guān)閉了。

案例二

使用全局搜索后居然占用了將近6%的CPU，這可是日常的流量下截取的火焰圖，系統(tǒng)流量升高時占用比例會更大。 點開后可以看到是進(jìn)行HSF調(diào)用的時候，獲取Java調(diào)用棧比較耗時，之前寫代碼的時候懷疑過獲取調(diào)用棧會比較耗性能，但沒想到居然比一次HSF調(diào)用本身的耗時都大了。這個地方之前是為了獲取調(diào)用來源，打印到日志中方便排查問題的(歷史代碼)，后續(xù)將HSF的調(diào)用日志改成了通過HSF Filter的方式，去掉了獲取調(diào)用棧的邏輯。 其實案例二我一開始不是從上往下看定位到的，因為調(diào)用HSF的地方不止一個，每個耗時其實也不長，整體看的話從上往下還是比較難發(fā)現(xiàn)的。

從下往上看

案例二

如果從上往下看效果不明顯，可以從我們系統(tǒng)主要流量入口處進(jìn)行分析，從下面入口一步步往上點，也可以發(fā)現(xiàn)問題，帶著懷疑的態(tài)度來找，上述的案例二我一開始并沒有注意到上方的問題，我是一步步從消息入口看，然后點到上面發(fā)現(xiàn)的這個調(diào)用消耗居然比HSF多的。

可以看到這個調(diào)用不是集中在一個地方的，細(xì)看每個地方都有調(diào)用，所以整體對性能的影響才那么大。 全局搜索后可以看到到處都有調(diào)用(圖示紫色部分)。

從下往上找更適合細(xì)化的時候，專門對某個鏈路進(jìn)行分析優(yōu)化。

優(yōu)化效果

下面來讓我們計算一下數(shù)據(jù)，來看看樓主是不是標(biāo)題黨了。

整體大致優(yōu)化了5~6%左右(7月份的時候，機(jī)器數(shù)量是30臺，8月縮容到了27臺)，取5%，其中系統(tǒng)CPU占用在6.5%左右，從日常流量上來看，用戶態(tài)cpu從26%到21%，下降19%+，考慮縮容的關(guān)系，20%的優(yōu)化大抵是有的。 由于這是日常流量的優(yōu)化結(jié)果，大促流量突增時，系統(tǒng)負(fù)載降低應(yīng)該會更明顯，優(yōu)化后大用戶批量操作時瞬時流量也基本不會有機(jī)器cpu占用超過60%了。 后續(xù)雙十一壓測也會繼續(xù)關(guān)注優(yōu)化，流量上升后更多問題可能就會暴露出來。