最近我們有一臺服務器上的Java進程總是在運行個兩三天後就無法響應請求了，具體現象如下：
- 請求業務返回狀態碼502，查看進程還在，意味著Java進程假死，無法響應請求了；
- 該Java進程佔比CPU較高，高達132.8%。
所以再次發生的時候我摘了這臺服務器，保留現場排查該Java應用程序存在什麼問題。
使用top命令查看服務器整體運行情況：
可以看到PID為14760的Java進程CPU佔比132.8%，內存佔用37.6%，內存倒是在合理範圍內，但是這個CPU就太高了。
接下來我們就根據線上的真實情況來一步一步排查出所運行程序的問題代碼。
建議大家收藏此文，以便大家遇到類似問題後可以參考排查步驟快速排查服務性能問題。
查看進程14760的線程堆棧信息
執行命令：
<code>top -Hp 14760/<code>
打印出當前進程的所有線程的運行情況：
發現PID為14767和14768的兩個線程的CPU佔比分別為47.8%和47.5%，而且TIME+佔比較大，說明這兩個線程一直在運行。
繼續使用jstack命令來查看這兩個線程的堆棧信息，jstack的基本命令格式如下：
<code>jstack| grep '16進制的線程Id' /<code>
可以通過如下命令獲取14767這個線程的16進制數值：
<code>printf '%x\\n' 14767/<code>
輸出：740f，執行jstack相關命令：
<code>jstack 14760 | grep -a 0x39af -C20 --color/<code>
其中這個-C20是顯示當前行的上下20行 ，如果沒有這個命令就只有孤零零的當前行，看不出更多有效的信息，輸出內容如下：
通過上圖就可以看到線程為什麼吃CPU了，如果顯示的是大家自己開發的業務代碼，相信大家直接就可以review代碼找出問題所在了。
但是有時候我們並不能根據線程Id就能查出有問題的代碼在哪裡，比如上圖這種情況，紅框裡的兩個線程是GC task Thread，說明線程一直在進行GC，而上面的其他線程則是出於WAITING等待狀態，也就是說造成Java服務進程假死的原因是因為JVM的長時間GC導致的Stop The World！
所以我們要找出來到底是什麼原因導致的進程一直在GC，而無法響應業務請求。
jstat命令排查GC信息
既然是GC有問題，那麼我們繼續使用jstat命令來查看JVM heap的信息。
先來快速瞭解一下jstat命令的介紹和用法。
jstat命令格式如下：
<code>jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]]/<count>/<interval>/<vmid>/<lines>/<option>/<code>
相關參數：
- -class：顯示加載class的數量以及所佔空間信息
- -compiled：顯示VM實時編譯的數量信息
- -gc：顯示gc的信息，查看gc的次數、時間
- -gccapacity:顯示VM內存中三代（young、old、perm）對象的使用和佔用大小
- -gcutil：統計gc信息
- -gcnew：統計VM年輕代信息
- -gcnewcapacity：VM年輕代對象的信息及佔用量
- -gcold：VM年老代信息
- -gcoldcapacity：VM年老代對象的信息及佔用量
- -gcpermcapacity：VM中永久代的信息及佔用量
- -printcompilation：當前VM執行的信息。
執行命令：
<code>jstat -gcutil 14760 1000/<code>
得出的GC Heap數據如圖所示：
其中：
- S0：倖存1區當前使用比例
- S1：倖存2區當前使用比例
- E：伊甸園區使用比例
- O：老年代使用比例
- M：元數據區使用比例
- CCS：壓縮使用比例
- YGC：年輕代垃圾回收次數
- FGC：老年代垃圾回收次數
- FGCT：老年代垃圾回收消耗時間
- GCT：垃圾回收消耗總時間
從圖中的數據可以發現E(Eden區)和O(Old區)的內存已經被耗盡了，佔比高達100%，FGC（Full GC）的次數高達23133次，FGCT（Full GC Time）總時間高達36221.931秒，每次FGC耗時36221.931/23133≈1.6秒，很顯然Java進程都把時間花在FGC上了。
jmap命令拿到dump日誌文件
通過以上數據分析，可以初步定為問題發生在程序的內存洩漏上。這時候就需要使用到jmap的命令了，我們可以通過jmap命令輸出指定Java進程的dump二進制文件：
<code>jmap -dump:format=b,file=heap.bin/<code>
導出的heap二進制文件大小竟然高達1.2G！
接下來開始用MAT工具分析拿到的dump文件，關於如何使用MAT(Memory Analyzer Tools)分析dump文件，可以查閱我的另一篇文章：
由於文件超過1個G，Mac下MAT的默認Xmx是1024m，所以我們需要加大MAT的最大可用內存，否則無法分析這麼大的文件。
打開MAT找到MAT在mac中的安裝位置：
編輯MemoryAnalyzer.ini文件裡面的xmx1024m為4096m：
保存後重啟MAT，查看原來的位置可以看見內容已經更改了：
開始分析dump文件！分析後得到的結果如圖所示：
可以看到org.hibernate.internal.SessionFactoryImpl這個實例佔用了853,310,632 (92.24%) 字節，共813.3MB！目前可以知道的是在Hibernate數據查詢這塊有問題，具體點擊Details繼續跟進去找問題代碼:]
圖中可以看到有問題的對象好幾個，佔用的內存也比較大。再來看下面一張圖：
Accumulated Objects by Class in Dominator Tree是支配樹中按類累積對象，可以看到BoundedConcurrentHashMap只有32個對象示例，其對象樹卻佔據了853241512字節的堆大小。我們點擊進去看看這個HashMap裡面都存儲了什麼數據：
把這個value拷貝出來，是我們業務的sql，看到這個sql我就驚訝了，這個sql傳了91976個參數！
至此，我們便找出了造成Java進程假死的代碼在這個SQL上。
毋庸置疑，這個SQL存在兩個大問題：
- SQL本身是慢SQL，不能迅速查出來；
- SQL本身查出來的數據需要分配更多的內存。
內存不足，需要回收對象，但是查詢SQL有需要更多的對象空間來存儲。因此這邊一直在GC，但是有回收不出來有效的空間，那就需要繼續GC。所以進程一直在FULL GC，導致一直stop the world。
以上就是本次線上生產環境關於Java進程假死的問題排查分析的步驟。
大家在遇到這種問題的時候，建議大家在不影響業務正常服務的情況下，保存好現場，把握住機會，然後迅速的找到本篇文章，按照上述排查步驟快速排查出問題代碼。
大家自己也可以寫一段有內存洩漏問題的程序，然後參考本文練習排查，提高自己排查問題的熟練度。避免臨陣磨槍，不慢也慌。
當然，線上問題排查也是一名高級工程師應該具備的能力之一。想進入一線互聯網公司，BAT大廠，這些技能必知必會！
感謝大家閱讀此文，如果對您有幫助，歡迎點贊、轉發。關注“java架構設計”，閱讀更多技術乾貨文章！
往期精彩回顧：
閱讀更多 java架構設計 的文章
