故障分析

# 導致系統不可用情況（頻率較大）：

    1）程式碼中某個位置讀取資料量較大，導致系統記憶體耗盡，進而出現Full GC次數過多，系統緩慢；

    2）程式碼中有比較消耗CPU的操作，導致CPU過高，系統執行緩慢；

# 導致某功能執行緩慢（不至於導致系統不可用）：

    3）程式碼某個位置有阻塞性的操作，導致呼叫整體比較耗時，但出現比較隨機；

    4）某執行緒由於某種原因進入WAITTING狀態，此時該功能整體不可用，但無法復現；

    5）由於鎖使用不當，導致多個執行緒進入死鎖狀態，導致系統整體比較緩慢。

# 說明

    對於後三種情況而言，是具有一定阻塞性操作，CPU和系統記憶體使用情況都不高，但功能卻很慢，所以通過檢視資源使用情況是無法查看出具體問題的！

應急處理

### 對於線上系統突然產生的執行緩慢問題，如果導致線上系統不可用。首先要做的是匯出jstack和記憶體資訊，重啟伺服器，儘快保證系統的高可用。

### 匯出jstack資訊

為避免重複贅述，此操作將在後面的"排查步驟"章節中體現！

### 匯出記憶體堆疊資訊

# 檢視要匯出的Java專案的pid

# jps -l

or

# ps -ef |grep java

# 匯出記憶體堆疊資訊

jmap -dump:live,format=b,file=heap8 <pid> # heap8是自定義的檔名

# 執行匯出的堆疊檔案

# ls

heap8

# hostname -I

10.2.2.162

# jhat -port 9998 heap8

# 瀏覽器訪問http://10.2.2.162:9998/

排查步驟

# 環境說明

    因平臺做了線上推廣，導致管理平臺門戶網頁進統計頁面請求超時，隨進伺服器作業系統檢視負載資訊，load average超過了4，負載較大，PID為7163的程序cpu資源佔用較高。

# 定位故障

# 處理思路：

    找出CPU佔用率高的執行緒，再通過執行緒棧資訊找出該執行緒當時正在執行的問題程式碼段。

# 操作如下：

# 檢視高佔用的"程序"中佔用高的"執行緒"

# top -Hbp 7163 | awk '/java/ && $9>50'

# 將16298的執行緒ID轉換為16進位制的執行緒ID

# printf "%x\n" 16298

3faa

# 通過jvm的jstack檢視程序資訊並儲存以供研發後續分析

# jstack 7163 | grep "3faa" -C 20 > 7163.log

# 重點說明

通過排查步驟，可得排查問題需要掌握的資訊如下：

    1）資源佔用高對應的程序a的PID;

    2）程序a對應的資源佔用高且最頻繁的執行緒b的ID；

    3）將執行緒b的ID轉換為16進位制的ID。

資料庫問題引發的資源佔用過高

## 通過"排查步驟"章節可基本定位問題，後續請見下文！

確認問題及處理

# jstack $pid | grep "3faa" -C 20 # 3faa指的是高佔用程序中的高佔用的執行緒對應的16進位制id；

# 檢視到是資料庫的問題，排查思路：先列印所有在跑的資料庫執行緒，檢查後發現並跟進情況找到問題表；

# 列印MySQL現有程序資訊檔案

# mysql -uroot -p -e "show full processlist" > mysql_full_process.log

# 過濾出查詢最多的表

grep Query mysql_full_process.log

# 統計查詢最多的表的資料量

> use databases_name；

> select count(1) from table_name；

# 結合MySQL日誌資訊，可判斷問題是查詢時間過長導致，排查後發現表未建立索引；

> show create table table_name\G

# 詢問研發，確認資料不重要，檢查欄位由時間欄位，根據時間確認只保留一個月的資料；

> delete from table_name where xxxx_time < '2019-07-01 00:00:00' or xxxx_time is null;

# 建立索引

> alter table table_name add index (device_uuid);

# 確認索引是否建立

> show create table table_name;

總結

    處理後進程的CPU佔用降至正常水平，本次排查主要用到了jvm程序檢視及dump程序詳細資訊的操作，確認是由資料庫問題導致的原因，並對資料庫進行了清理並建立了索引。

    在處理問題後，又查詢了一下資料庫相關問題的優化，通常的優化方法還是新增索引。該方法新增引數具體如下：

innodb_buffer_pool_size=4G

Full GC次數過多

## 通過"排查步驟"章節可基本定位問題，後續請見下文！

確認問題及處理

# 特徵說明

對於Full GC較多的情況，有以下特徵：

    1）程序的多個執行緒的CPU使用率都超過100%，通過jstack命令可看到大部分是垃圾回收執行緒；

    2）通過jstat檢視GC情況，可看到Full GC次數非常多，並數值在不斷增加。

# 3faa指的是高佔用程序中的高佔用的執行緒對應的16進位制id；

# jstack $pid | grep "3faa" -C 20

說明：VM Thread指垃圾回收的執行緒。故基本可確定，當前系統緩慢的原因主要是垃圾回收過於頻繁，導致GC停頓時間較長。

# 檢視GC情況（1000指間隔1000ms，4指查詢次數）

# jstat -gcutil $pid 1000 4

說明：FGC指Full GC數量，其值一直在增加，圖中顯現高達6783，進一步證實是由於記憶體溢位導致的系統緩慢。

# 因筆者是運維，故確認了問題後，Dump記憶體日誌後交由研發解決程式碼層面問題！

總結

# 對於Full GC次數過大，主要有以下兩種原因：

    1）程式碼中一次性獲取大量物件，導致記憶體溢位（可用Eclipse的Mat工具排查）；

    2）記憶體佔用不高，但Full GC數值較大，可能是顯示的System.gc()呼叫GC次數過多，可通過新增 -XX:+DisableExplicitGC 來禁用JVM 對顯示 GC 的響應。

服務不定期出現介面響應緩慢

情況說明

    某個介面訪問經常需要3~4s甚至更長時間才能返回。一般而言，其消耗的CPU和記憶體資源不多，通過上述方式排查問題無法行通。

    由於介面耗時較長問題不定時出現，導致通過jstack命令得到執行緒訪問的堆疊資訊，根據其資訊也不一定能定位到導致耗時操作的執行緒（概率事件）。

定位思路

    在排除網路因素後，通過壓測工具對問題介面不斷加大訪問力度。當該介面中有某個位置是比較耗時的，由於訪問的頻率高，將導致大多數的執行緒都阻塞於該阻塞點。

    通過分析多個執行緒日誌，能得到相同的TIMED_WAITING堆疊日誌，基本上就可定位到該介面中較耗時的程式碼的位置。

# 示例

# 程式碼中有比較耗時的阻塞操作，通過壓測工具得到的執行緒堆疊日誌，如下：

說明：由圖可得，多個執行緒都阻塞在了UserController的第18行，說明此時一個阻塞點，也是導致該介面較緩慢的原因。

大總結

# 總體性的分析思路

當Java應用出現問題時，處理步驟如下：

    通過 top 命令定位CPU資源佔用較高的程序pid，再 top -Hp <pid> 命令定位出CPU資源佔用較高的執行緒的id，並將其執行緒id轉換為十六進位制的表現形式，再通過 jstack <pid> | grep <id> 命令檢視日誌資訊，定位具體問題。

# 此處根據日誌資訊分析，可分為兩種情況，如下：

# A情況    

    A.a）若使用者執行緒正常，則通過該執行緒的堆疊資訊檢視比較消耗CPU的具體程式碼區域；

    A.b）若是VM Thread，則通過 jstat -gcutil <pid> <interval> <times> 命令檢視當前GC狀態，然後通過 jmap -dump:live,format=b,file=<filepath> <pid> 匯出當前系統記憶體資料，用Eclipse的Mat工具進行分析，進而針對比較消耗記憶體的程式碼區進行相關優化。

# B情況

    若通過top命令檢視到CPU和記憶體使用率不高，則可考慮以下三種情況。

    B.a）若是不定時出現介面耗時過長，則可通過壓測方式增大阻塞點出現的概率，從而通過jstack命令檢視堆疊資訊，找到阻塞點；

    B.b）若是某功能訪問時突然出現停滯（異常）狀況，重啟後又正常了，同時也無法復現。此時可通過多次匯出jstack日誌的方式，對比並定位出較長時間處於等待狀態的使用者執行緒，再從中篩選出問題執行緒；

    B.c）若通過jstack命令檢視到死鎖狀態，則可檢查產生死鎖的執行緒的具體阻塞點，進而相應處理。