cpu使用率飆高排查過程

1、背景
     最近兩週夥拼其中的一臺task機器每隔幾天老是報警cpu利用率飆高的問題，由於一直在忙項目。因此前幾回都是經過重啓任務臨時解決。這種狀況出現兩次以後，今天終於抽出時間來排查這個問題，在此分享一下，這個cpu使用率飆高的問題的排查過程，方便你們之後遇到一樣的問題能夠有參考。


2、排查思路和過程
1.經過top命令查看佔用cpu比較高的進程id。
       以下圖所示，可以看到進程爲164065這個進程cpu佔比很高，629.4%，只要能眼睛沒毛病的都能看出來，明顯164065這個進程有貓膩。




2.既然164065這個進程有貓膩，那咱們就看看這個有貓膩的進程是個什麼鬼。
      經過pe  -ef | grep164065 ,能夠看到，這是夥拼的一個活動掃描任務。任務的執行內容就不說了。




3.既然164065這個jvm進程有問題，那麼咱們就須要定位到這個進程裏面具體是什麼線程有貓膩。
      經過top -Hp 164065,能夠看到原來是164069，164070，164071，164072這四個線程的cpu佔比達這麼高。




4.咱們再繼續深刻，探探這四個線程到底是幹嗎的
     那麼怎麼看164069，164070，164071，164072這四個線程是幹嗎的呢？別急，咱們先轉成16進制。轉換以後分別是280e5，280e6，280e7，280e8



5.轉成16進制之後，再經過jstack 164065能夠看到具體的線程信息。
以下圖所示，哈哈，終於逮到你了，原來是GC的4個線程在搞鬼。


6.爲何GC的這四個線程的cpu使用佔比一直這麼高？
     既然是進行GC的線程，咱們固然要來看一下堆內存的情況了。經過jmap -heap 164065  咱們來簡單看一下堆內存吧。WTF,新生代的空間已經用了100%，老年代的空間的使用也達到了99.87%。看到這裏，估計你們都明白了。爲啥GC線程會不停的佔用cpu。原來是堆內存的新生代和老年代的空間不夠了，須要進行fullGC和minorGC，可是每次fullGC和monorGC只能釋放一點點空間，而後很快又達到了須要GC的程度。再進行GC，如此循環致使GC的線程瘋狂調用。必需要強調的是，這裏正好達到了即將發生OOM，可是尚未發生OOM，立馬進行GC這麼一個平衡。因此GC線程才能如此囂張的佔用CPU.




7. 經過jstat -GC pid，咱們來查看一下GC的頻率。
     咦，圖呢？很差意思，當時太激動了忘了截圖了，總之minorGC和fullGC執行頻率之高使人咋舌。

8.咱們繼續來分析，爲何堆內存會這麼不夠用呢。
     立馬想到的就是分析dump。好，咱們經過jmap -dump:format=b,file=taskDump.bin 生產dump文件，而後經過zprofiler對堆內存進行分析（不要問我爲何要手動打印dump，由於這臺機器上有N個jvm進程，zprofile貌似不能指定進程）。能夠看到這個dump文件裏面有三個對象很是大，加在一塊兒基本上有300M。而咱們這個進程的jvm 堆內存配置的最大才512M。這三個大對象都是forest包裏面的，再聯想到兩週前才作過viewcache到forest的遷移，這兩週開始出現的cpu利用率飆高的謎題終於真相大白了。





2、解決辦法
      解決辦法很簡單，加大JVM的堆內存配置大小。同時通知一下forest那邊的團隊，大家的常駐堆內存的對象太大了，要不要進行優化一下。


3、總結
       由於兩週以前接入了forest，結果forest的三個大對象有300M之大，而咱們的JVM配置的最大可以使用內存才512M.致使JVM堆內存中的新生代和老年代的使用內存達到了一個很巧妙的平衡（即將OOM，可是通過GC還能挽回），在這個平衡下，jvm的GC線程會去瘋狂的進行minorGC和fullGC，從而致使CPU利用率飆高。經過仔細分析，把兩個看似不相干的問題卻聯繫到了一塊兒。這個思路針對於一些JVM應用cpu佔用飆高的問題的解決應該有所幫助，因此花了點時間記錄下並分享出來。