一.前言

各位開發和運維同學，在專案實施落地的過程中，尤其是使用EDAS、DRDS、MQ這些java中介軟體時，肯定會遇到不少JAVA程式執行和JVM的問題。我結合過去遇到的各種各樣的問題和實際處理經驗，總結了JAVA問題的處理方式，希望能幫助到大家。

二.問題處理總體概括

如下圖所示：

問題處理分為三大類：
1.問題發生後的緊急處理原則
2.問題歸類和分析
3.分析排查工具和命令
通常來說，最後的解決方式有兩種，第一種是最普遍的，絕大部分的最終問題原因可以定位到程式碼層面，修改程式碼後問題解決。
第二種，調整某些JVM引數，緩解問題發生的頻率和時間，但是治標不治本，所以本篇分析文件並未涉及JVM引數的優化調整。

三.緊急處理原則

問題發生後，第一時間是快速保留問題現場供後面排查定位，然後儘快恢復服務。保留現場的具體操作：

• 列印堆疊資訊，命令列：jstat -l `java程式PID`
• 列印記憶體映象，命令列：jmap -dump:format=b,file=hprof `java程式PID`
• 生成core檔案，命令列：gcore `java程式PID`
• 保留gc日誌檔案
• 保留業務日誌檔案
• 檢視JAVA堆記憶體執行分配：命令列：jstat -gcutil `java程式PID` 1000
• 完成以上操作後，儘快重啟JAVA程式或回滾，恢復服務。

四.問題歸類和分析

當應用系統執行緩慢，頁面載入時間變長，後臺長時間無影響時，都可以參考以下歸類的解決方法。絕大部分的JAVA程式執行時異常都是Full GC、OOM(java.lang.OutOfMemoryError)、執行緒過多。主要分這麼幾大類：

• 持續發生Full GC，但是系統不丟擲OOM錯誤
• 堆記憶體溢位：java.lang.OutOfMemoryError：Java heap space
• 執行緒過多：java.lang.OutOfMemoryError：unable to create new native thread
• JAVA程式退出
• CPU佔用過高

通常來說，可以用一些常用的命令列來列印堆疊、記憶體使用分配、列印記憶體映象檔案來分析，比如jstack、jstat、jmap等。但是某些時刻，還是需要引入更高階的程式碼級分析工具（比如btrace）才能定位到具體原因。針對每一種問題，我會依據具體的case來詳細說明解決方式。

五.分析排查工具和命令

問題排查，除了最重要的解決思路外，合理的運用工具也能達到事半功倍的效果，某些時候用好了工具，甚至能直接定位到導致問題的具體程式碼。

JDK自帶工具

Jstat

實時檢視gc的狀況，通過jstat -gcutil 可以檢視new區、old區等堆空間的記憶體使用詳情，以及gc發生的次數和時間

Jstack

很重要的命令，jstack可以用來檢視Java程式裡的執行緒都在幹什麼，對於應用沒反應、響應非常慢等場景都有很大的幫助。幾乎所有java問題排查時，我第一選擇都是使用jstack命令列印執行緒資訊。

Jmap

jmap -dump用於儲存堆記憶體映象檔案，供後續MAT或其他的記憶體分析工具使用。jmap -histo:live也可以強制執行full gc。

Jinfo

通常我用它來檢視Java的啟動引數

gcore

我通常會使用gcore命令來保留問題現場，速度非常快。某些時候執行jstack或jmap會報錯，加-F也不行，這個時候就可以用gcore命令，gcore javapid 可以生成core檔案，可以通過jstack和jmap命令從core檔案裡匯出執行緒和記憶體映象檔案。

堆記憶體分析工具

MAT

eclipse官方推出的本地記憶體分析工具，執行需要大量記憶體，從使用角度來講，並不方便。我現在已經很少使用。

ZProfiler

阿里中介軟體出品的線上堆記憶體分析工具，連結是：zprofiler.alibaba-inc.com，不需要拷貝映象檔案，直接線上分析。

EagleEye-MProf

也是阿里中介軟體團隊推出的，適用於複雜雲環境的輕量級java堆記憶體分析工具，非常好用。在公共雲或者專有云的機器上，執行的是客戶的機器。由於許可權或者網路的關係，我們很難去執行jmap進行heap dump，或者scp上傳dump檔案。這個工具可以直接在ECS上分析，而不用下載dump檔案。

程式碼跟蹤工具

Btrace

Java程式碼動態跟蹤神器。少數的問題可以mat後直接看出，而多數會需要再用btrace去動態跟蹤。比如排查執行緒建立過多的場景，通過btrace可以直接定位到哪段程式碼建立了大量執行緒。
比較麻煩的就是要自行編寫指令碼，不過現成的指令碼也有不少，可以直接使用。

六.案例分析一：持續出現Full GC

處理原則

如果發現cms gc或full gc後，存活的物件始終很多，這種情況下可以通過jmap -dump來獲取下記憶體dump檔案，也可以通過gcore命令生成core檔案，再用jmap從core裡匯出dump檔案。然後通過MAT、ZProfile、EagleEye-MProf來分析記憶體映象分佈。如果還不能定位，最後使用btrace來定位到具體的原因。對於cms gc而言，還有可能會出現promotion failed或concurrent mode failure問題。

分析過程

1. 檢視GC日誌：

發現應用系統一直在做full gc，而且還有報錯“concurrent mode failure”，這表示在執行gc過程中，有物件要晉升到舊生代，而此時舊生代空間不足造成的。

2. 檢視應用訪問日誌：

有條很可疑的訪問記錄，響應時間特別長，達到了60S，直接超時了。

3. 檢視JVM記憶體分配詳情：

如何判斷JVM垃圾回收是否正常，我通常會使用jstat命令，jstat是JDK自帶的一個輕量級小工具。全稱“Java Virtual Machine statistics monitoring tool”，它位於java的bin目錄下，主要利用JVM內建的指令對Java應用程式的資源和效能進行實時的命令列的監控，包括了對Heap size和垃圾回收狀況的監控。可見，jstat是輕量級的、專門針對JVM的工具，非常適用。jstat工具特別強大，有眾多的可選項，詳細檢視堆內各個部分的使用量，以及載入類的數量。使用時，需加上檢視程式的程式id，和所選引數。
執行：cd $JAVA_HOME/bin中執行jstat，注意jstat後一定要跟引數。
具體命令列：jstat -gcutil `java程式PID` 1000

如圖所示，發現Eden區、Old區都滿了，此時新建立的物件無法存放，晉升到Old區的物件也無法存放，所以系統持續出現Full GC了。

4. 分析記憶體映象：

這種問題比較直觀，需要dump記憶體映象，然後用MAT或者Zprofiler工具分析heapdump檔案。
MAT(Memory Analyzer Tool)，一個基於 Eclipse 的記憶體分析工具，是一個快速、功能豐富的 JAVA heap 分析工具，它可以幫助我們查詢記憶體洩漏問題。
Zprofiler是阿里中介軟體團隊推出的線上JAVA記憶體分析工具，不用在本地執行，訪問http://zprofiler.alibaba-inc.com/ 即可。
儲存記憶體映象的命令：jmap -dump:format=b,file=hprof `java程式PID`，通常來講這個檔案會比較大，一般都會有好幾個G。
用MAT或ZProfile分析結果如下，基本定位了問題的原因



很明顯，LinkedHashMap佔用了91.41%的記憶體，裡面有大量的ThRoomQuotaDO的引用物件，很有可能是死迴圈造成了這樣的現象。不過要尋找真實原因，還得看看具體的程式碼。

5. 檢視原始碼

查詢ThRoomQuotaDO類的原始碼，發現了導致死迴圈的程式碼，如下：

程式碼段一：
`if(start == null || end == null || start.before(now)){

          start = CalendarUtil.addDate(now, 1);
          end = CalendarUtil.addDate(start,1);`

這裡的start和end就是之前應用訪問日誌裡的那條get請求帶進來的，請求的url如下：

請注意start=2010-04-031061，本來這個start的值是不規範的，但程式碼還是通過SimpleDateFormat把start解析成的Date為(Fri Apr 15 00:00:00 CST 2095)，所以不會進入程式碼段一的if塊中去。

程式碼段二：
`Map roomQuotaMapFull = new LinkedHashMap();
for (Date d = hotelQuery.getStart(); d.compareTo(hotelQuery.getEnd()) != 0; d = CalendarUtil.addDate(d, 1)) {

                 ThRoomQuotaDO rq = new ThRoomQuotaDO();
                 rq.setTheDate(d);
                 rq.setMock();
                 roomQuotaMapFull.put(d, rq);

}`

這裡就是最終導致full gc的程式碼：d.compareTo(hotelQuery.getEnd()) != 0，顯然start和end是不相等的，所以陷入死迴圈中，以致把記憶體塞滿了。
因此，最終的原因得到了定位，要解決起來那就很容易了。

6. 解決

程式碼段一：
修改導致問題的程式碼（標紅處是修改後的）
if(start == null || end == null || start.before(now))|| start.after(end)){

          start = CalendarUtil.addDate(now, 1);
          end = CalendarUtil.addDate(start,1);

}

程式碼段二：
for (Date d = hotelQuery.getStart();d.compareTo(hotelQuery.getEnd()) <= 0 ;d = CalendarUtil.addDate(d, 1)) {

                 ThRoomQuotaDO rq = new ThRoomQuotaDO();
                 rq.setTheDate(d);
                 rq.setMock();
                 roomQuotaMapFull.put(d, rq);

}

重新打包釋出後，記憶體恢復正常，再也沒有發生此類問題。

案例分析二：OOM：unable to create new native thread

處理原則

在日誌中可能會看到java.lang.OutOfMemoryError: Unable to create new native thread，可以先統計下目前的執行緒數(例如ps -eLf | grep java -c)，然後可以看看ulimit -u的限制值是多少，如執行緒數已經達到限制值，如限制值可調整，則可通過調整限制值來解決；如不能調限制值，或者建立的執行緒已經很多了，那就需要看看執行緒都是哪裡建立出來的，首先用jstack命令列印執行緒堆疊資訊，統計執行緒狀態，然後通過btrace來查出是哪裡建立的執行緒。
如果jstack執行失敗的話，可以使用gcore命令生成core檔案：gcore javapid > core.**
然後再用jstack和jmap可以匯出堆疊和記憶體映象檔案。
具體命令：jstack $JAVA_HOME/bin/java core.** > jstack.log

分析過程

1. 檢視GC日誌：

發現gc都正常，沒有full gc，new區，old區都正常，確定不是heap堆出問題。

2. 檢視應用訪問日誌：

發現業務日誌中有很多錯誤：

3. 檢視執行緒堆疊：

檢視jstack.log堆疊資訊發現一共有8204個執行緒，其中blocked的有8169個，明顯不正常。通過堆疊資訊不能看出是什麼導致建立了這麼多執行緒，但是至少能確定導致oom的原因了：執行緒建立太多，且全部block了。下面就需要用btrace工具跟進分析具體是什麼程式碼建立了這麼多的執行緒。

4. 使用Btrace工具分析：

編寫btrace指令碼ThreadStart.java，內容如下：
`import static com.sun.btrace.BTraceUtils.*;
import com.sun.btrace.annotations.*;
@BTrace public class Trace{
@OnMethod(

   clazz="java.lang.Thread",
   method="start"

)
public static void traceExecute(){

    jstack();

}
}`

執行命令：./btrace javapid ThreadStart.java > thread.log
檢視thread.log，到這裡可以確定問題所在了，基本上所有的執行緒都在這個類裡建立：com.taobao.et.web.ie.module.action.IeOrderCheckAction.doMileageMeta

5. 檢視原始碼

從程式碼裡可以看到，每次執行doMileageMeta都會建立一個執行緒池，但是沒有shutdown釋放資源。

問題原因就清楚了:應用啟動後，每次請求都會建立一個包含3個執行緒的執行緒池，但是從不釋放資源，漲到8000多個以後，達到執行緒上限，丟擲了”unable to create new native thread”。

6. 解決

修改程式碼：每次建立執行緒池後，呼叫shutdown方法來釋放資源，具體程式碼就不帖出來了。

案例分析三：OOM：java heap space

處理原則

java.lang.OutOfMemoryError: java heap size也是常見的現象。最重要的是dump出記憶體，一種方法是通過在啟動引數上增加-XX:+HeapDumpOnOutOfMemoryError，另一種方法是在當出現OOM時，通過jmap -dump獲取到記憶體dump，在獲取到記憶體dump檔案後，可通過MAT進行分析，但通常來說僅僅靠MAT可能還不能直接定位到具體應用程式碼中哪個部分造成的問題，例如MAT有可能看到是某個執行緒建立了很大的ArrayList，但這樣是不足以解決問題的，所以通常還需要藉助btrace來定位到具體的程式碼。

案例分析四：Java程式退出

處理原則

對於Java程式退出，最重要的是要讓系統自動生成coredump檔案，需要設定ulimit -c unlimited，表示core檔案為不限制大小，通常會加到java應用的啟動指令碼里。當程式crash發生時，找到coredump檔案，core檔案通常位於 /應用部署目錄/target (core檔案一般在程式工作區產生)下。有可能的原因是程式碼中出現了無限遞迴或死迴圈，可通過jstack來提取出Java的執行緒堆疊，從而具體定位到具體的程式碼。
如果以上方法無效時，可以嘗試dmesg命令，看看系統出了什麼問題，有可能是系統主動殺掉了Java程式（例如記憶體超出限制）

分析過程

1.生成coredump檔案

在將出現crash的伺服器上開啟ulimit,等待生成core檔案，執行命令：ulimit -c unlimited 。

2.分析coredump檔案

執行命令：gdb -c $JAVA_HOME/bin/java coredump_file
鍵入：info threads —– 獲取core檔案中執行緒資訊
其中*號前代表是crash時，當前正在執行的執行緒
即當前正在執行的執行緒為 9406

3.使用jstack命令分析core檔案，獲取指定執行緒id對應的程式碼資訊

具體命令：jstack $JAVA_HOME/bin/java coredump_file > jstack.log，搜尋剛才得到的執行緒編號 9406，發現問題如下：

原因就是程式碼裡出現了無限遞迴，導致了爆棧。

案例分析五：CPU佔用過高

處理原則

從經驗上來說，有些時候是由於頻繁cms gc或fgc造成的，在gc log是記錄的情況下（-Xloggc:），可通過gc log看看，如果沒開啟gc log，可通過jstat -gcutil來檢視，如是gc頻繁造成的，則可跳到後面的記憶體問題 | GC頻繁部分看排查方法。

如不是上面的原因，可使用top -H檢視執行緒的cpu消耗狀況，這裡有可能會看到有個別執行緒是cpu消耗的主體，這種情況通常會比較好解決，可根據top看到的執行緒id進行十六進位制的轉換，用轉換出來的值和jstack出來的java執行緒堆疊的nid=0x[十六進位制的執行緒id]進行關聯，即可看到此執行緒到底在做什麼動作，這個時候需要進一步的去排查到底是什麼原因造成的，例如有可能是正則計算，有可能是很深的遞迴或迴圈，也有可能是錯誤的在併發場景使用HashMap等。

分析過程

這裡分享下如何檢視具體導致CPU高的執行緒名稱
1.找到最耗CPU資源的java執行緒TID
執行命令：ps H -eo user,pid,ppid,tid,time,%cpu,cmd | grep java | sort -k6 -nr |head -1
2.將找到的執行緒TID進行十六進位制的轉換
printf “%xn” tid
3.從堆疊檔案裡找到對應的執行緒名稱
通過命令匯出堆疊檔案：jstack javapid > jstack.log，根據上一步得到的執行緒TID，搜尋堆疊檔案，即可看到此執行緒到底在做什麼動作。