1. 程式人生 > >火焰圖--記一次cpu降溫過程

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

引子   

  正值週末,娃兒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 '%x\n' 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的問題,相信以後的再有這樣的情況會從容一些。因為經驗不足,文章中也有很多不足的地方,歡迎指出;如果覺得有用,也歡迎點贊鼓勵。

 

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