轉:https://www.cnblogs.com/wanghaoyang/p/11687329.html
問題現象:線上系統突然運行緩慢,CPU飆升,甚至到100%,以及Full GC次數過多,接着就是各種報警:例如接口超時報警等。此時急需快速線上排查問題。
核心排查步驟:
1.執行“top”命令:查看所有進程占系統CPU的排序。極大可能排第一個的就是咱們的java進程(COMMAND列)。PID那一列就是進程號。
2.執行“top -Hp 進程號”命令:查看java進程下的所有線程占CPU的情況。
3.執行“printf "%x\n 10"命令 :后續查看線程堆棧信息展示的都是十六進制,為了找到咱們的線程堆棧信息,咱們需要把線程號轉成16進制。例如, printf "%x\n 10145" -》打印:a,那么在jstack中線程號就是0xa.
4.執行 “jstack 進程號 | grep 線程ID” 查找某進程下 -》線程ID(jstack堆棧信息中的nid)=0xa的線程堆棧信息。如果“"VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable”,第一個雙引號圈起來的就是線程名,如果是“VM Thread”這就是虛擬機GC回收線程了
5.執行“jstat -gcutil 進程號 統計間隔毫秒 統計次數(缺省代表一致統計)”,查看某進程GC持續變化情況,如果發現返回中FGC很大且一直增大-》確認Full GC! 也可以使用“jmap -heap 進程ID”查看一下進程的堆內從是不是要溢出了,特別是老年代內從使用情況一般是達到閾值(具體看垃圾回收器和啟動時配置的閾值)就會進程Full GC。
6.執行“jmap -dump:format=b,file=filename 進程ID”,導出某進程下內存heap輸出到文件中。可以通過eclipse的mat工具查看內存中有哪些對象比較多。
以下是發現解決問題的具體流程。
1:通過#top命令查看,我的java服務確實把CPU幾乎占滿了,如圖
可看到18400這個進程CPU占用達到了1200%,這確實不太正常,那么我們接下來分析到底哪些線程占用了CPU
2:通過#top -Hp 18400這條命令我們可以看到這個進程中線程的情況,部分截圖如下。

通過截圖可以看到,前面的線程占用的CPU是比較高的,那我們就具體分析這些線程
3:我們通過#jstack 18400>18400.txt命令將這個java進程的線程棧給抓出來,可以多抓幾次做個對比。
我們以18414這個線程為例,將它轉成16進制,linux可以用終端通過命令#printf "%x" 18414將線程id轉為16進制為47ee,那么我們接下來在文件里找47ee這個線程在干什么,部分截圖如下

我們可以看到47ee是個垃圾回收線程;我們對其他占用CPU高的線程做相同的操作,發現都是GC線程。說明這個java服務一直在GC,這很不正常。那么我們接下來分析GC情況。
4:我們通過命令#jstat -gcutil 18400 1000 100來查看接下開的GC情況,部分截圖如下
是不是很直觀,通過YGC這一列發現younggc次數沒有增加,但是通過FGC這一列看到fullgc的次數一直在增加,可怕的是老年代並沒有回收(通過O這列看出來)。
這時候你是不是想起來了一個名詞:內存泄露。沒錯,接下來我們就需要分析哪里出現了內存泄露。
5:我們可以通過#jmap -dump:live,format=b,file=18400.dump 18400將這個進程當前的堆給dump下來。注意,這個文件可以看成是堆的快照,所以當前堆有多大,dump下來差不多也有多大。我dump下來的差不多2G。
有了這個文件,我們需要分析,你可以用命令jhat分析,當然我們常用的是功能比較強大的圖形化工具,如JDK自帶的visualvm,也可以用第三方的JProfiler(我用的是這個),如果你用Eclipse,也可以安裝MAT插件。這些工具都能分析堆dump文件。
需要注意的是,由於dump文件可能比較大,所以所需分析工具的內存也比較大,最好在性能比較好的機器上進行分析。
下面是我的JProfiler分析的部分截圖

是不是很直觀,有個對象占了97%的內存。那么接下來需要分析這個對象在哪產生,在哪被引用。我這里很明顯是這個LinkedList占用了全部空間,那么就去分析這個LinkedList里面都存了些什么,這些有可能需要結合你的代碼,我就不細說了。
我分析出來的是ElasticSearch的客戶端工具JestClient的異步請求隊列太長了,整個List里面的節點都是異步請求信息,大概生成了10多萬個。消費不及時又無法被回收,所以產生了內存泄露。(注意,使用線程池也有可能會出現這個情況)
6:分析出了原因,那么接下來就解決問題。因為我當時急着上線,不知道JestClient的異步隊列長度怎么配,就暫時把異步改成了同步,暫時解決了這個問題。上線后查看CPU,垃圾回收等情況確實恢復了正常。
總的來說,上面的6步是一個完整的分析解決jvm虛擬機內存泄露的流程,當然可能有不完善的地方,但大體思路是沒錯的。
通過這篇文章,我們可以總結出以下幾點:
1:如何分析Java服務占用CPU過高的問題
2:使用Java各種隊列的時候一定要關注隊列的長度,預防內存泄露。
3:最好熟悉一下jvm的內存模型
原因分析
1.內存消耗過大,導致Full GC次數過多
執行步驟1-5:
- 多個線程的CPU都超過了100%,通過jstack命令可以看到這些線程主要是垃圾回收線程-》上一節步驟2
- 通過jstat命令監控GC情況,可以看到Full GC次數非常多,並且次數在不斷增加。--》上一節步驟5
確定是Full GC,接下來找到具體原因:
- 生成大量的對象,導致內存溢出-》執行步驟6,查看具體內存對象占用情況。
- 內存占用不高,但是Full GC次數還是比較多,此時可能是代碼中手動調用 System.gc()導致GC次數過多, 這可以通過添加 -XX:+DisableExplicitGC來禁用JVM對顯示GC的響應。
2.代碼中有大量消耗CPU的操作,導致CPU過高,系統運行緩慢;
執行步驟1-4:在步驟4 jstack,可直接定位到代碼行。例如某些復雜算法,甚至算法BUG,無限循環遞歸等等。
3.由於鎖使用不當,導致死鎖。
執行步驟1-4: 如果有死鎖,會直接提示。關鍵字:deadlock. 步驟四,會打印出業務死鎖的位置。
造成死鎖的原因:最典型的就是2個線程互相等待對方持有的鎖。
4.隨機出現大量線程訪問接口緩慢。
代碼某個位置有阻塞性的操作,導致該功能調用整體比較耗時,但出現是比較隨機的;平時消耗的CPU不多,而且占用的內存也不高。
