快速定位Java服務(wù)線上“系統(tǒng)性”故障

參考自 http://techblog.youdao.com/?p=961

在分析具體故障，先介紹一下幾種常用的工具

JDK中帶有了一堆的工具是可以用來查看運(yùn)行狀況，排查問題的，但對(duì)于這些工具還是要比較清楚執(zhí)行后會(huì)發(fā)生什么，否則有可能會(huì)因?yàn)閳?zhí)行了一個(gè)命令就導(dǎo)致嚴(yán)重故障，首先重點(diǎn)講下影響比較大的jmap。

最主要的危險(xiǎn)操作是下面這三種：
1.jmap -dump
jmap -dump:format=b,file=heap.hprof 1234。
這個(gè)命令執(zhí)行，JVM會(huì)將整個(gè)heap的信息dump寫入到一個(gè)文件，heap如果比較大的話，就會(huì)導(dǎo)致這個(gè)過程比較耗時(shí)，并且執(zhí)行的過程中為了保證dump的信息是可靠的，所以會(huì)暫停應(yīng)用。
可以通過-d64來解決(jmap -J-d64 -dump:format=b,file=dump.bin PID)
而jdk7的某個(gè)版本則會(huì)拋出異常，這是jdk的bug.
一般dump下來的內(nèi)存有幾個(gè)G，而有時(shí)候dump下來只有一兩百兆，說明jmap有問題，需要多執(zhí)行幾次jmap -dump才能得出正常結(jié)果，這個(gè)時(shí)候可以選用
gcore 把整個(gè)內(nèi)存dump出來，然后再使用jmap把core dump轉(zhuǎn)換成heap dump。
做法就是用gcore 1234命令來生成c版的core文件，再用命令jmap -dump:format=b,file=heap.hprof /bin/java core.1234.

2.jmap -permstat
這個(gè)命令執(zhí)行，JVM會(huì)去統(tǒng)計(jì)perm區(qū)的狀況，這整個(gè)過程也會(huì)比較的耗時(shí)，并且同樣也會(huì)暫停應(yīng)用。

**3. jmap -histo:live **
這個(gè)命令執(zhí)行，JVM會(huì)先觸發(fā)gc，然后再統(tǒng)計(jì)信息。

jmap導(dǎo)出的文件怎么進(jìn)行分析呢，這時(shí)候就會(huì)用到一些分析工具，我比較常用的是 IBM HeapAnalyzer工具，具體的用法大家自己查一下，啟動(dòng)方法如下
java -jar -Xmx3000m ha455.jar

另外一個(gè)比較常用工具是jstat,jstat是JDK自帶的一個(gè)輕量級(jí)小工具。全稱“Java Virtual Machine statistics monitoring tool”，它位于Java的bin目錄下，主要利用JVM內(nèi)建的指令對(duì)Java應(yīng)用程序的資源和性能進(jìn)行實(shí)時(shí)的命令行的監(jiān)控，包括了對(duì)Heap size和垃圾回收狀況的監(jiān)控?？梢姡琂stat是輕量級(jí)的、專門針對(duì)JVM的工具，非常適用。
jstat工具特別強(qiáng)大，有眾多的可選項(xiàng)，詳細(xì)查看堆內(nèi)各個(gè)部分的使用量，以及加載類的數(shù)量。使用時(shí)，需加上查看進(jìn)程的進(jìn)程id，和所選參數(shù)。我比較常用的是如下命令1234 代表進(jìn)程號(hào)，1000，10 代表每1秒輸入一次JVM資源使用情況，共輸出10次。
**jstat -gcutil 1234 1000 10 **

另外排查OOM通常要結(jié)合tomcat的日志、gc日志來查看。如果沒有任何JVM參數(shù)設(shè)置，gc日志默認(rèn)打印在stdout.log文件里，里面可能會(huì)打其他的日志，而且GC日志也不會(huì)輸出時(shí)間，所以在JVM啟動(dòng)參數(shù)里最好加以下命令，規(guī)范下GC日志輸出到/home/admin/logs/gc.log，并且打印GC時(shí)間。
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/home/admin/logs
-Xloggc:/home/admin/logs/gc.log
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps

下面進(jìn)入正題

一、摘要

由于硬件問題、系統(tǒng)資源緊缺或者程序本身的BUG，Java服務(wù)在線上不可避免地會(huì)出現(xiàn)一些“系統(tǒng)性”故障，比如：服務(wù)性能明顯下降、部分（或所有）接口超時(shí)或卡死等。其中部分故障隱藏頗深，對(duì)運(yùn)維和開發(fā)造成長(zhǎng)期困擾。筆者根據(jù)自己的學(xué)習(xí)和實(shí)踐，總結(jié)出一套行之有效的“逐步排除”的方法，來快速定位Java服務(wù)線上“系統(tǒng)性”故障。

二、導(dǎo)言

Java語言是廣泛使用的語言，它具有跨平臺(tái)的特性和易學(xué)易用的特點(diǎn)，很多服務(wù)端應(yīng)用都采用Java語言開發(fā)。由于軟件系統(tǒng)本身以及運(yùn)行環(huán)境的復(fù)雜性，Java的應(yīng)用不可避免地會(huì)出現(xiàn)一些故障。盡管故障的表象通常比較明顯（服務(wù)反應(yīng)明顯變慢、輸出發(fā)生錯(cuò)誤、發(fā)生崩潰等），但故障定位卻并不一定容易。為什么呢？有如下原因：

  1. 程序打印的日志越詳細(xì)，越容易定位到BUG，但是可能有些時(shí)候程序中沒有打印相關(guān)內(nèi)容到日志，或者日志級(jí)別沒有設(shè)置到相應(yīng)級(jí)別

  2. 程序可能只對(duì)很特殊的輸入條件發(fā)生故障，但輸入條件難以推斷和復(fù)現(xiàn)

  3. 通常自己編寫的程序出現(xiàn)的問題會(huì)比較容易定位，但應(yīng)用經(jīng)常是由多人協(xié)作編寫，故障定位人員可能并不熟悉其他人員編寫的程序

  4. 應(yīng)用通常會(huì)依賴很多第三方庫，第三方庫中隱藏著的BUG可能是始料未及的

  5. 多數(shù)的開發(fā)人員學(xué)習(xí)的都是“如何編寫業(yè)務(wù)功能”的技術(shù)資料，但對(duì)于“如何編寫高效、可靠的程序”、“如何定位程序故障”卻知之甚少。所以一旦應(yīng)用出現(xiàn)故障，他們并沒有足夠的技術(shù)背景知識(shí)來幫助他們完成故障定位。

盡管有些故障會(huì)很難定位，但筆者根據(jù)學(xué)習(xí)和實(shí)踐總結(jié)出一套“逐步排除”的故障定位方法：通過操作系統(tǒng)和Java虛擬機(jī)提供的監(jiān)控和診斷工具，獲取到系統(tǒng)資源和目標(biāo)服務(wù)（出現(xiàn)故障的Java服務(wù)）內(nèi)部的狀態(tài)，并依據(jù)服務(wù)程序的特點(diǎn)，識(shí)別出哪些現(xiàn)象是正常的，哪些現(xiàn)象是異常的。而后通過排除正常的現(xiàn)象，和跟蹤異常現(xiàn)象，就可以達(dá)到****故障定位的目標(biāo)。

在正式介紹該方法之前，先申明一下這個(gè)方法使用的范圍。

三、本方法適用的范圍

本方法主要適用于Linux系統(tǒng)中Java服務(wù)線上“系統(tǒng)性”故障的定位，比如：服務(wù)性能明顯下降、部分（或所有）接口超時(shí)或卡死。其它操作系統(tǒng)或其它語言的服務(wù)，也可以參考本文的思路。

不適用本方法的情況：對(duì)于“功能性”故障，例如運(yùn)算結(jié)果不對(duì)、邏輯分支走錯(cuò)等，不建議使用本方法。對(duì)待這些情況比較恰當(dāng)?shù)姆椒ㄊ窃跍y(cè)試環(huán)境中重現(xiàn)，并使用Java虛擬機(jī)提供的“遠(yuǎn)程調(diào)試”功能進(jìn)行動(dòng)態(tài)跟蹤調(diào)試。

前面說過，本方法基于“異?，F(xiàn)象”的識(shí)別來定位故障。那系統(tǒng)中可能有哪些異常現(xiàn)象呢？

四、有哪些異?，F(xiàn)象

我們可以將異?，F(xiàn)象分成兩類：系統(tǒng)資源的異?，F(xiàn)象、“目標(biāo)服務(wù)”內(nèi)部的異?，F(xiàn)象。目標(biāo)服務(wù)，指的是出現(xiàn)故障的Java服務(wù)。

  1. 系統(tǒng)資源的異常現(xiàn)象
    一個(gè)程序由于BUG或者配置不當(dāng)，可能會(huì)占用過多的系統(tǒng)資源，導(dǎo)致系統(tǒng)資源匱乏。這時(shí)，系統(tǒng)中其它程序就會(huì)出現(xiàn)計(jì)算緩慢、超時(shí)、操作失敗等“系統(tǒng)性”故障。常見的系統(tǒng)資源異?，F(xiàn)象有：CPU占用過高、物理內(nèi)存富余量極少、磁盤I/O占用過高、發(fā)生換入換出過多、網(wǎng)絡(luò)鏈接數(shù)過多。可以通過top、iostat、vmstat、netstat工具獲取到相應(yīng)情況。

  2. 目標(biāo)服務(wù)內(nèi)部的異常現(xiàn)象
    Java堆滿Java堆是“Java虛擬機(jī)”從操作系統(tǒng)申請(qǐng)到的一大塊內(nèi)存，用于存放Java程序運(yùn)行中創(chuàng)建的對(duì)象。當(dāng)Java堆滿或者較滿的情況下，會(huì)觸發(fā)“Java虛擬機(jī)”的“垃圾收集”操作，將所有“不可達(dá)對(duì)象”（即程序邏輯不能引用到的對(duì)象）清理掉。有時(shí)，由于程序邏輯或者Java堆參數(shù)設(shè)置的問題，會(huì)導(dǎo)致“可達(dá)對(duì)象”（即程序邏輯可以引用到的對(duì)象）占滿了Java堆。這時(shí)，Java虛擬機(jī)就會(huì)無休止地做“垃圾回收”操作，使得整個(gè)Java程序會(huì)進(jìn)入卡死狀態(tài)。我們可以使用jstat工具查看Java堆的占用率。
    日志中的異常目標(biāo)服務(wù)可能會(huì)在日志中記錄一些異常信息，例如超時(shí)、操作失敗等信息，其中可能含有系統(tǒng)故障的關(guān)鍵信息。
    疑難雜癥死鎖、死循環(huán)、數(shù)據(jù)結(jié)構(gòu)異常（過大或者被破壞）、集中等待外部服務(wù)回應(yīng)等現(xiàn)象。這些異常現(xiàn)象通常采用jstack工具可以獲取到非常有用的線索。

了解異常現(xiàn)象分類之后，我們來具體講講故障定位的步驟。

五、故障定位的步驟

我們采用“從外到內(nèi)，逐步排除”的方式來定位故障：

  1. 先排除其它程序過度占用系統(tǒng)資源的問題
  2. 然后排除“目標(biāo)服務(wù)”本身占用系統(tǒng)資源過度的問題
  3. 最后觀察目標(biāo)服務(wù)內(nèi)部的情況，排除掉各種常見故障類型。
    對(duì)于不能排除的方面，要根據(jù)該信息對(duì)應(yīng)的“危險(xiǎn)程度”來判斷是應(yīng)該“進(jìn)一步深入”還是“暫時(shí)跳過”。例如“目標(biāo)服務(wù)Java堆占用100%”這是一條危險(xiǎn)程度較高的信息，建議立即“進(jìn)一步深入”。而對(duì)于“在CPU核數(shù)為8的機(jī)器上，其它程序偶然占用CPU達(dá)200%”這種危險(xiǎn)程度不是很高的信息，則建議“暫時(shí)跳過”。當(dāng)然，有些具體情況還需要故障排查人員根據(jù)自己的經(jīng)驗(yàn)做出判斷。

第一步：排除其它程序占用過量系統(tǒng)資源的情況


圖示：排除其它程序占用過量系統(tǒng)資源的情況

  1. 運(yùn)行【top】，檢查CPU idle情況，如果發(fā)現(xiàn)idle較多（例如多余50%），則排除其它進(jìn)程占用CPU過量的情況。

    如果idle較少，則按shift+p，將進(jìn)程按照CPU占用率從高到低排序，逐一排查（見下面TIP）。

  2. 運(yùn)行【free -g】，檢查剩余物理內(nèi)存（“-/+ buffer/cache”行的“free”列）情況，如果發(fā)現(xiàn)剩余物理內(nèi)存較多（例如剩余2GB以上），則排除占用物理內(nèi)存過量的情況。


    如果剩余物理內(nèi)存較少（例如剩余1GB以下），則運(yùn)行【vmstat -n 1】檢查si/so（換入換出）情況，
    vmstat

    第一行數(shù)值表示的是從系統(tǒng)啟動(dòng)到運(yùn)行命令時(shí)的均值，我們忽略掉。從第二行開始，每一行的si/so表示該秒內(nèi)si/so的block數(shù)。如果多行數(shù)值都為零，則可以排除物理內(nèi)存不足的問題。如果數(shù)值較大（例如大于1000 blocks/sec，block的大小一般是1KB）則說明存在較明顯的內(nèi)存不足問題。我們可以運(yùn)行【top】輸入shift+m，將進(jìn)程按照物理內(nèi)存占用（“RES”列）從大到小進(jìn)行排序，然后對(duì)排前面的進(jìn)程逐一排查（見下面TIP）。

  3. 如果目標(biāo)服務(wù)是磁盤I/O較重的程序，則用【iostat -d 1】，檢查磁盤I/O情況。若“目標(biāo)服務(wù)對(duì)應(yīng)的磁盤”讀寫量在預(yù)估之內(nèi)（預(yù)估要注意cache機(jī)制的影響），則排除其它進(jìn)程占用磁盤I/O過量的問題。


    第一組數(shù)據(jù)是從該機(jī)器從開機(jī)以來的統(tǒng)計(jì)值。從第二組開始，都是每秒鐘的統(tǒng)計(jì)值。通過【df】命令，可以看到Device與目錄的關(guān)系。下圖設(shè)備“sdb”就對(duì)應(yīng)了目錄“/disk2”。
    df

假如發(fā)現(xiàn)目標(biāo)服務(wù)所在磁盤讀寫量明顯超過推算值，則應(yīng)該找到大量讀寫磁盤的進(jìn)程（見下面TIP）

4.運(yùn)行【netstat -aonp | grep tcp| wc -l】查看各種狀態(tài)的TCP連接數(shù)量和。如果總數(shù)較小（例如小于500），則排除連接數(shù)占用過多問題。
假如發(fā)現(xiàn)連接數(shù)較多，可以用【netstat -natp|awk ‘{print $7}’|sort|uniq -c|sort -rn】按照PID統(tǒng)計(jì)TCP連接的數(shù)量，然后對(duì)連接數(shù)較多的進(jìn)程逐一排查（見下面TIP）。

TIP：如何“逐一排查”：假如定位到是某個(gè)外部程序占用過量系統(tǒng)資源，則依據(jù)進(jìn)程的功能和配置情況判斷是否合乎預(yù)期。假如符合預(yù)期，則考慮將服務(wù)遷移到其他機(jī)器、修改程序運(yùn)行的磁盤、修改程序配置等方式解決。假如不符合預(yù)期，則可能是運(yùn)行者對(duì)該程序不太了解或者是該程序發(fā)生了BUG。外部程序通?？赡苁荍ava程序也可能不是Java程序，如果是Java程序，可以把它當(dāng)作目標(biāo)服務(wù)一樣進(jìn)行排查；而非Java程序具體排查方法超出了本文范圍，列出三個(gè)工具供參考選用：
系統(tǒng)提供的調(diào)用棧的轉(zhuǎn)儲(chǔ)工具【pstack】，可以了解到程序中各個(gè)線程當(dāng)前正在干什么，從而了解到什么邏輯占用了CPU、什么邏輯占用了磁盤等
系統(tǒng)提供的調(diào)用跟蹤工具【strace】，可以偵測(cè)到程序中每個(gè)系統(tǒng)API調(diào)用的參數(shù)、返回值、調(diào)用時(shí)間等。從而確認(rèn)程序與系統(tǒng)API交互是否正常等。
系統(tǒng)提供的調(diào)試器【gdb】，可以設(shè)置條件斷點(diǎn)偵測(cè)某個(gè)系統(tǒng)函數(shù)調(diào)用的時(shí)候調(diào)用棧是什么樣的。從而了解到什么邏輯不斷在分配內(nèi)存、什么邏輯不斷在創(chuàng)建新連接等

TIP：如何“找到大量讀寫磁盤的進(jìn)程”：

  1. 如果Linux系統(tǒng)比較新（kernel v2.6.20以上）可以使用iotop工具獲知每個(gè)進(jìn)程的io情況，較快地定位到讀寫磁盤較多的進(jìn)程。
  2. 通過【ls -l /proc/*/fd | grep 該設(shè)備映射裝載到的文件系統(tǒng)路徑】查看到哪個(gè)進(jìn)程打開了該設(shè)備的文件，并根據(jù)進(jìn)程身份、打開的文件名、文件大小等屬性判斷是否做了大量讀寫。
  3. 可以使用pstack取得進(jìn)程的線程調(diào)用棧，或者strace跟蹤磁盤讀寫API來幫助確認(rèn)某個(gè)進(jìn)程是否在做磁盤做大量讀寫

第二步：排除目標(biāo)服務(wù)占用了過量系統(tǒng)資源的情況


圖示：排除目標(biāo)服務(wù)占用了過量系統(tǒng)資源的情況
1.** 運(yùn)行【top】，shift+p按照“CPU使用”從高到低的排序查看進(jìn)程，假如目標(biāo)服務(wù)占用的CPU較低（<100%，即小于一個(gè)核的計(jì)算量），或者符合經(jīng)驗(yàn)預(yù)期，則排除目標(biāo)服務(wù)CPU占用過高的問題。**
假如目標(biāo)服務(wù)占用的CPU較高（>100%，即大于一個(gè)核的計(jì)算量），則shift+h觀察線程級(jí)別的CPU使用分布。
如果CPU使用分散到多個(gè)線程，而且每個(gè)線程占用都不算高（例如都<30%），則排除CPU占用過高的問題
如果CPU使用集中到一個(gè)或幾個(gè)線程，而且很高（例如都>95%），則用【jstack pid > jstack.log】獲取目標(biāo)服務(wù)中線程調(diào)用棧的情況。top中看到的占用CPU較高的線程的PID轉(zhuǎn)換成16進(jìn)制（字母用小寫），然后在jstack.log中找到對(duì)應(yīng)線程，檢查其邏輯：假如對(duì)應(yīng)線程是純計(jì)算型任務(wù)（例如GC、正則匹配、數(shù)值計(jì)算等），則排除CPU占用過高的問題。當(dāng)然如果這種線程占用CPU總量如果過多（例如占滿了所有核），則需要對(duì)線程數(shù)量做控制（限制線程數(shù) < CPU核數(shù)）。
假如對(duì)應(yīng)線程不是純計(jì)算型任務(wù)（例如只是向其他服務(wù)請(qǐng)求一些數(shù)據(jù)，然后簡(jiǎn)單組合一下返回給用戶等），而該線程CPU占用過高（>95%），則可能發(fā)生了異常。例如：死循環(huán)、數(shù)據(jù)結(jié)構(gòu)過大等問題，確定具體原因的方法見下文“第三步：目標(biāo)進(jìn)程內(nèi)部觀察”。

2.** 運(yùn)行【top】，shift+m按照“物理內(nèi)存使用(RES)”從高到低排序進(jìn)程，評(píng)估目標(biāo)服務(wù)占的內(nèi)存量是否在預(yù)期之內(nèi)。如果在預(yù)期之內(nèi)，則排除目標(biāo)服務(wù)Native內(nèi)存占用過高的問題。**
提示：由于Java進(jìn)程中有Java級(jí)別的內(nèi)存占用，也有Native級(jí)別的內(nèi)存占用，所以Java進(jìn)程的“物理內(nèi)存使用(RES)”比“-Xmx參數(shù)指定的Java堆大小”大一些是正常的（例如1.5~2倍左右）。
假如“物理內(nèi)存使用(RES)”超出預(yù)期較多（例如2倍以上），并且確定JNI邏輯不應(yīng)該占用這么多內(nèi)存，則可能是NIO或JNI代碼出現(xiàn)了BUG。由于本文主要討論的是Java級(jí)別的問題，所以對(duì)這種情況不做過多討論。讀者可以參考上文“TIP：如何逐一排查”進(jìn)行native級(jí)別的調(diào)試。

第三步：目標(biāo)服務(wù)內(nèi)部觀察


圖示：目標(biāo)服務(wù)內(nèi)部觀察
1. Java堆占用情況
** 用【jstat -gcutil pid】查看目標(biāo)服務(wù)的OLD區(qū)占用比例，假如占用比例低于85%則排除Java堆占用比例過高的問題。**
假如占用比例較高（例如超過98%），則服務(wù)存在Java堆占滿的問題。這時(shí)候可以用jmap+mat進(jìn)行分析定位內(nèi)存中占用比例的情況（見下文TIP），從而較快地定位到Java堆滿的原因。

TIP：用jmap+mat進(jìn)行分析定位內(nèi)存中占用比例的情況
先通過【jmap -dump:file=dump.map pid】取得目標(biāo)服務(wù)的Java堆轉(zhuǎn)儲(chǔ)，然后找一臺(tái)空閑內(nèi)存較大的機(jī)器在VNC中運(yùn)行mat工具。mat工具中打開dump.map后，可以方便地分析內(nèi)存中什么對(duì)象引用了大量的對(duì)象（從邏輯意義上來說，就是該對(duì)象占用了多大比例的內(nèi)存）。具體使用可以ca

2. 異常日志觀察
通過類似【tail -10000 stdout.log.2014-08-15 | grep -B2 -A10 -i exception】這樣的方式，可以查到日志中最近記錄的異常。

3. 疑難雜癥
用【jstack pid > jstack.log】獲取目標(biāo)服務(wù)中“鎖情況”和“各線程調(diào)用?！毙畔?，并分析
檢查jstack.log中是否有deadlock報(bào)出，如果沒有則排除deadlock情況。

*Found one Java-level deadlock:*

*=============================*

*“Thread-0″:*

*  waiting to lock monitor 0x1884337c (object 0x046ac698, a java.lang.Object),*

*  which is held by “main”*

*“main”:*

*  waiting to lock monitor 0x188426e4 (object 0x046ac6a0, a java.lang.Object),*

*  which is held by “Thread-0″*

* *
*Java stack information for the threads listed above:*
*===================================================*
*“Thread-0″:*
* at LockProblem$T2.run(LockProblem.java:14)*
* - waiting to lock <0x046ac698> (a java.lang.Object)*
* - locked <0x046ac6a0> (a java.lang.Object)*
*“main”:*
* at LockProblem.main(LockProblem.java:25)*
* - waiting to lock <0x046ac6a0> (a java.lang.Object)*
* - locked <0x046ac698> (a java.lang.Object)*
* *
*Found 1 deadlock.*

如果發(fā)現(xiàn)deadlock則則根據(jù)jstack.log中的提示定位到對(duì)應(yīng)代碼邏輯。
用【POST http://www.xinitek.com/ajax/summaryJStack < jstack.log > jstack.log.summary】對(duì)jstack.log做合并處理，然后繼續(xù)分析故障所在。

通過jstack.log.summary中的情況，我們可以較迅速地定位到一些嫌疑點(diǎn)，并可以猜測(cè)其故障引起的原因（后文有jstack.log.summary情況舉例供參考）

Paste_Image.png

猜測(cè)了原因后，可以通過日志檢查、監(jiān)控檢查、用測(cè)試程序嘗試復(fù)現(xiàn)等方式確認(rèn)猜測(cè)是否正確。如果需要更細(xì)致的證據(jù)來確認(rèn)，可以通過BTrace、strace、jmap+MAT等工具進(jìn)行分析，最終確認(rèn)問題所在。

下面簡(jiǎn)單介紹下這幾個(gè)工具：
BTrace：用于監(jiān)測(cè)Java級(jí)別的方法調(diào)用情況?？梢詫?duì)運(yùn)行中的Java虛擬機(jī)插入調(diào)試代碼，從而確認(rèn)方法每次調(diào)用的參數(shù)、返回值、花費(fèi)時(shí)間等。第三方免費(fèi)工具。
strace：用于監(jiān)視系統(tǒng)調(diào)用情況?？梢缘玫矫看蜗到y(tǒng)調(diào)用的參數(shù)、返回值、耗費(fèi)時(shí)間等。Linux自帶工具。
jmap+MAT：用于查看Java級(jí)別內(nèi)存情況。jmap是JDK自帶工具，可以將Java程序的Java堆轉(zhuǎn)儲(chǔ)到數(shù)據(jù)文件中；MAT是eclipse.org上提供的一個(gè)工具，可以檢查jmap轉(zhuǎn)儲(chǔ)數(shù)據(jù)文件中的數(shù)據(jù)。結(jié)合這兩個(gè)工具，我們可以非常容易地看到Java程序內(nèi)存中所有對(duì)象及其屬性。

TIP：jstack.log.summary情況舉例
1.某種線程數(shù)量過多

*1000 threads at*
*“Timer-0″ prio=6 tid=0x189e3800 nid=0x34e0 in Object.wait() [0x18c2f000]*
*   java.lang.Thread.State: TIMED_WAITING (on object monitor)*
* at java.lang.Object.wait(Native Method)*
* at java.util.TimerThread.mainLoop(Timer.java:552)*
* - locked [***] (a java.util.TaskQueue)*
* at java.util.TimerThread.run(Timer.java:505)*

2.多個(gè)線程在等待一把鎖，但拿到鎖的線程在做數(shù)據(jù)結(jié)構(gòu)遍歷操作

*38 threads at*
*“Thread-44″ prio=6 tid=0×18981800 nid=0x3a08 waiting for monitor entry [0x1a85f000]*
*   java.lang.Thread.State: BLOCKED (on object monitor)*
* at SlowAction$Users.run(SlowAction.java:15)*
* - waiting to lock [***] (a java.lang.Object)*

* *
*1 threads at*
*“Thread-3″ prio=6 tid=0x1894f400 nid=0×3954 runnable [0x18d1f000]*
*   java.lang.Thread.State: RUNNABLE*
* at java.util.LinkedList.indexOf(LinkedList.java:603)*
* at java.util.LinkedList.contains(LinkedList.java:315)*
* at SlowAction$Users.run(SlowAction.java:18)*
* - locked [***] (a java.lang.Object)*

3.某個(gè)應(yīng)當(dāng)被緩存的對(duì)象多次被創(chuàng)建（數(shù)據(jù)庫連接）

99 threads at
“resin-tcp-connection-*:3231-321″ daemon prio=10 tid=0x000000004dc43800 nid=0x65f5 waiting for monitor entry [0x00000000507ff000]
    java.lang.Thread.State: BLOCKED (on object monitor)
         at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:290)
         - waiting to lock <0x00000000b26ee8a8> (a org.apache.commons.dbcp.PoolableConnectionFactory)
         at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:771)
         at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:95)
* *
1 threads 
at “resin-tcp-connection-*:3231-149″ daemon prio=10 tid=0x000000004d67e800 nid=0x66d7 runnable [0x000000005180f000]
 java.lang.Thread.State: RUNNABLE
  …
at org.apache.commons.dbcp.DriverManagerConnectionFactory.createConnection(DriverManagerConnectionFactory.java:46)
at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:290)
 - locked <0x00000000b26ee8a8> (a org.apache.commons.dbcp.PoolableConnectionFactory)
at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:771)
at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:95)
at …

4.很多線程都在等待外部服務(wù)的響應(yīng)

100 threads at
“Thread-0″ prio=6 tid=0x189cdc00 nid=0×2904 runnable [0x18d5f000]
java.lang.Thread.State: RUNNABLE
atjava.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)…
at RequestingService$RPCThread.run(RequestingService.java:24)

5.很多線程都在等待FutureTask完成，而FutureTask在等待外部服務(wù)的響應(yīng)

100 threads at
“Thread-0″ prio=6 tid=0×18861000 nid=0x38b0 waiting on condition [0x1951f000]
   java.lang.Thread.State: WAITING (parking)
 at sun.misc.Unsafe.park(Native Method)
 - parking to wait for [***] (a java.util.concurrent.FutureTask$Sync)
 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
 at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:248)
 at java.util.concurrent.FutureTask.get(FutureTask.java:111)
 at IndirectWait$MyThread.run(IndirectWait.java:51)
 
100 threads at
“pool-1-thread-1″ prio=6 tid=0x188fc000 nid=0×2834 runnable [0x1d71f000]
java.lang.Thread.State: RUNNABLEat java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)…
at IndirectWait.request(IndirectWait.java:23)
at IndirectWait$MyThread$1.call(IndirectWait.java:46)
at IndirectWait$MyThread$1.call(IndirectWait.java:1)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)

為方便讀者使用，將故障定位三個(gè)步驟的圖合并如下：

all

圖示：故障定位步驟匯總

故障定位是一個(gè)較復(fù)雜和需要經(jīng)驗(yàn)的過程，如果現(xiàn)在故障正在發(fā)生，對(duì)于分析經(jīng)驗(yàn)不很多的開發(fā)或運(yùn)維人員，有什么簡(jiǎn)單的操作步驟記錄下需要的信息嗎？下面提供一個(gè)

六、給運(yùn)維人員的簡(jiǎn)單步驟

如果事發(fā)突然且不能留著現(xiàn)場(chǎng)太久，要求運(yùn)維人員：

  1. top: 記錄cpu idle%。如果發(fā)現(xiàn)cpu占用過高，則c, shift+h, shift + p查看線程占用CPU情況，并記錄
  2. free: 查看內(nèi)存情況，如果剩余量較小，則top中shift+m查看內(nèi)存占用情況，并記錄
  3. 如果top中發(fā)現(xiàn)占用資源較多的進(jìn)程名稱（例如java這樣的通用名稱）不太能說明進(jìn)程身份，則要用ps xuf | grep java等方式記錄下具體進(jìn)程的身份
  4. 取jstack結(jié)果。假如取不到，嘗試加/F
    jstack命令：jstack PID > jstack.log
  5. jstat查看OLD區(qū)占用率。如果占用率到達(dá)或接近100%，則jmap取結(jié)果。假如取不到，嘗試加/F
    jstat命令： jstat -gcutil PID
    S0 S1 E O P YGC YGCT FGC FGCT GCT
    0.00 21.35 88.01 97.35 59.89 111461 1904.894 1458 291.369 2196.263
    jmap命令： ** jmap -dump:file=dump.map PID**
  6. 重啟服務(wù)

七、參考資料
BTrace官網(wǎng)
MAT官網(wǎng)
使用jmap和MAT觀察Java程序內(nèi)存數(shù)據(jù)
使用Eclipse遠(yuǎn)程調(diào)試Java應(yīng)用程序
Linux下輸入【man strace/top/iostat/vmstat/netstat/jstack】

最后編輯于 ：
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成，瀏覽時(shí)請(qǐng)結(jié)合常識(shí)與多方信息審慎甄別。
平臺(tái)聲明：文章內(nèi)容（如有圖片或視頻亦包括在內(nèi)）由作者上傳并發(fā)布，文章內(nèi)容僅代表作者本人觀點(diǎn)，簡(jiǎn)書系信息發(fā)布平臺(tái)，僅提供信息存儲(chǔ)服務(wù)。

相關(guān)閱讀更多精彩內(nèi)容

友情鏈接更多精彩內(nèi)容