火焰圖–記一次cpu降溫過程

• 2020 年 4 月 5 日
• 筆記

引子　　　

　　正值周末，娃兒6:30又如鬧鈴般準時來叫醒了我們。年前離開美菜，又回到了杭州。原本是想有更多時間陪伴娃兒，然而新的工作節奏與工作地點，讓我們每天都是早上見面；這不，為了周末可以多玩一會兒，早早就過來喚醒我們。因為前幾天我們就約好了周末一起放風箏。有些事兒，我以為只是隨口一說，小孩子確真真的記著。

　　吃過早飯，拉著媳婦兒，領著娃，帶上風箏就出門了。其實我是忐忑的，因為我也從來沒有把風箏放起來過。來到草坪上，娃就拉著風箏如脫韁之馬跑了起來。小孩子的幸福就這麼簡單，無關乎風箏能飛多高。

　　迎著暖暖朝陽，吹著徐徐春風，一下子感覺2周加班的疲憊都消散了。然而，一陣兒急促的“釘釘”聲打破了難得的寧靜：Warning， ***applicaiton， cpu 高於51%，持續2分鐘。此服務涉及大部分單車投放操作，目前是新老並用，我們是新服務，tps不高，但業務非常重要。於是拉著還未盡興的娃兒，回去處理問題了。當然我的內心是緊張而喜悅的，每次的故障就是一次學習的機會。

問題分析　　

　　既然是cpu告警，首先查看cpu最近的使用情況，一看得到兩條資訊：1，下圖中剪頭所指的地方就是促發告警的閥值，2，cpu一直在40-50%上下徘徊 。

 我想大家看到這個圖也明白了：告警是正常的，目前cpu的情況很容易就會促發告警。反思一分鐘：整天埋頭支撐業務，連繫統的如此重要指標都沒有關注到。然後迅速回憶最近上線的功能，想到2月底，上線過電子鎖的需求，但是系統已經無法查看2月分的cpu日誌，接下來我們需要去找出問題。

排除記憶體原因

　　平時很少有處理生產環境cpu過高問題，真正碰到這樣的場景還是蒙圈的。看看網上好些帖子都是說: heap 記憶體不足，分配記憶體失敗，會導致cpu偏高。首先使用jstat -gcutil 查看記憶體使用情況，如下圖，可見 新生代的區域 survivor0, survivor1,  eden 以及老生代都正常，FGC 也正常。 

jstat -gcutil 參數說明如下

重新再來

　　 遇到問題，猜是需要經驗的，瞎忙是沒用的，既然沒經驗那就一步一步來驗證吧；

      1， ps -ef | grep java 找到進程id   27931

　　2,  top -H -p 9527 找到佔cpu的執行緒

    3,  使用jstack 分別找也上面的執行緒的具體內容，比如第一個執行緒 28045。

      a,  轉化執行緒id為16進位   printf ‘%xn’ 28045，輸出 6d8d， 因為jstack 中執行緒id 是16進位的。

      b，jstack  27931 | grep 6d8d ，找到此執行緒

     c， 再用同樣的方法，發現其他幾個執行緒也是 kafka 消費者引起的。

    4，知道問題在於消費kafka了，原來上次做電子鎖需求時，為了拿到開鎖結果，監聽了一個kafka topic，這是一個特別核心的topic（後來聽其他同事說，這是公司消息量最多的上個topic了），

隨手查了下一個小時的數據26億/h，也就是 70w/s,  如此巨大的tps, 而此服務只有兩個結點，cpu維持在50%左右就不奇怪了。

　 到這裡，我還想再深究下，到底時哪幾行程式碼佔了cpu,  那應該如何找到這些程式碼呢。說來真是特別巧，上周5聽了測試同學的性能測試分享，後來還找時間了解了其中的火焰圖（flame graph）和arthas ， 對就是“火焰圖”- 今天的主角兒。關於火焰圖有幾個基本的知識就可以簡單分析了：　　

1，y-axis 表示調用父子關係，下面函數是上面的parent;

2 x-axis 表示抽樣合併的結果，越寬表示調用頻率越高，即執行的時間長；

3 顏色，左右，沒有特別的意義。

    一開始看到火焰圖，也是特別蒙圈的，下面有幾個文章特別不錯，英文文檔讀起來不算太複雜，中文的似乎就是翻譯英文文檔。

   英文文檔：

　http://www.brendangregg.com/flamegraphs.html , https://queue.acm.org/detail.cfm?id=2927301

   中文說明：

   http://www.ruanyifeng.com/blog/2017/09/flame-graph.html

   火焰圖demo:

　https://queue.acm.org/downloads/2016/Gregg7.svg

火焰圖實踐

　　 1，clone javaFlameGraph，git 地址如下：https://github.com/saquibkhan/javaFlameGraph，

       有一個地方要特別注意下：javaFlameGraph 核心是調用 FlameGraph中的實現，如圖中剪頭所指的項目，要確保FlameGraph也下載了。

　　 2，拉出一個節點摘掉流量，上傳clone的文件。

　　 3，到上傳文件的所在目錄執行  ./flame-gen.sh 27931  ，等待30s, control +c 就開始生成報告了。

 　　4，報告為當前目錄下的  flame.html ,  找開就是生成的火焰圖了。如下圖。

      這個圖是可交互的，可以點擊每個長方形獲取更多詳情的資訊，如圖，可看到有很多都是消耗都是 fastjson的 perseobject，因為我們每收到一個消息，會使用fastjson解析，過濾出指定的消息。

　說明下其中幾個除kafka相關執行緒外的執行緒，參考文章地址：https://blog.csdn.net/clamaa/article/details/70045983

　　DestroyJavaVM：

執行main()的執行緒在main執行完後調用JNI中的 jni_DestroyJavaVM() 方法喚起DestroyJavaVM 執行緒。JVM在伺服器啟動之後，就會喚起DestroyJavaVM執行緒，處於等待狀態，等待其它執行緒（java執行緒和native執行緒）退出時通知它卸載JVM。執行緒退出時，都會判斷自己當前是否是整個JVM中最後一個非daemon執行緒，如果是，則通知DestroyJavaVM 執行緒卸載JVM。

　　Surrogate Locker Thread：

這個執行緒主要用於配合CMS垃圾回收器使用，它是一個守護執行緒，其主要負責處理GC過程中，Java層的Reference（指軟引用、弱引用等等）與jvm 內部層面的對象狀態同步。

結語

　　因為工作的原因，很少有機會處理高tps場景下的問題，終於理性的分析了一次生產環境cpu的問題，相信以後的再有這樣的情況會從容一些。因為經驗不足，文章中也有很多不足的地方，歡迎指出；如果覺得有用，也歡迎點贊鼓勵。

　　 成為一名優秀的程式設計師！