JVM Crash日志分析

IT那活兒發(fā)布于2023-01-11 13:20 / 2539人閱讀

JVM Crash日志分析

JVM Crash即JAVA應(yīng)用程序在運行過程中因為某些致命錯誤導(dǎo)致JVM崩潰，JAVA進程非正常退出。應(yīng)用程序錯誤，JVM參數(shù)設(shè)置不當(dāng)，服務(wù)資源不足，jni調(diào)用錯誤，java虛擬機自身bug等等，都可能是導(dǎo)致JVM Crash的元兇。那么如何分析此類故障呢?

hs_err_pid.log日志文件獲取

當(dāng)JVM Crash發(fā)生時，Java虛擬機會自動產(chǎn)生一個快照，記錄故障時刻系統(tǒng)的各類運行信息，即hs_err_pid.log日志。缺省情況下該日志文件會產(chǎn)生在工作目錄下，當(dāng)然我們也可以通過JVM參數(shù)指定文件生成路徑：

-XX:ErrorFile=./hs_err_pid.log

Carsh日志文件分析

日志文件記錄了11類關(guān)鍵信息，如果在不是很熟悉日志結(jié)構(gòu)的情況下，往往不容易抓住重點。下面用一個實際的crash日志來逐步揭開它的面紗。

日志頭

日志頭文件包含概要信息，簡述了導(dǎo)致crash的原因。

如上圖為一個日志投文件信息，此處有一個重要信息” SIGBUS (0x7)”,SIGBUS(Bus error)意味著指針?biāo)鶎?yīng)的地址是有效地址，但總線不能正常使用該指針，通常是未對齊的數(shù)據(jù)訪問所致。其中SIGBUG為信號名，0x7是信號碼，pc=0x0000003267c8995b指的是程序計數(shù)器的值，pid=60801是進程號，tid=0x00002b5e1ab2a700是線程號。另外，還有一個重要信息，問題幀的信息：

這表示Crash時JVM正在從那個庫文件執(zhí)行代碼，這里”C”表示Native C frame，除此之外，還有可能是“j”、“V”、“v”，它們分別表示：

j: Interpreted Java frame

V: VMframe

v: VMgenerated stub frame

J: Other frame types, including compiled Java frames

導(dǎo)致crash的線程信息

文件下面是導(dǎo)致crash的線程信息和該線程棧信息，這部分內(nèi)容包含觸發(fā) JVM 致命錯誤的線程詳細(xì)信息和線程棧。

以上表示導(dǎo)致出錯的線程是0x00002b62e8028000（指針），線程類型是JavaThread表示執(zhí)行的是java線程，關(guān)于該線程其它類型還可能是：

VMThread：
jvm的內(nèi)部線程
CompilerThread：
用來調(diào)用JITing，實時編譯裝卸class 。通常，jvm會啟動多個線程來處理這部分工作，線程名稱后面的數(shù)字也會累加，例如：CompilerThread1
GCTaskThread：
執(zhí)行g(shù)c的線程
WatcherThread：
jvm周期性任務(wù)調(diào)度的線程，是一個單例對象。該線程在JVM內(nèi)使用得比較頻繁，比如：定期的內(nèi)存監(jiān)控、JVM運行狀況監(jiān)控，還有我們經(jīng)常需要去執(zhí)行一些jstat 這類命令查看gc的情況
ConcurrentMarkSweepThread：
jvm在進行CMS GC的時候，會創(chuàng)建一個該線程去進行GC，該線程被創(chuàng)建的同時會創(chuàng)建一個SurrogateLockerThread（簡稱SLT）線程并且啟動它，SLT啟動之后，處于等待階段。CMST開始GC時，會發(fā)一個消息給SLT讓它去獲取Java層Reference對象的全局鎖：Lock

后面的"HsfServerHandler-xx.xxx.x.xx:10250-thread-300"表示線程名，“daemon”表示該線程為守護線程，再后面的“[_thread_in_native”表示線程當(dāng)前狀態(tài)，關(guān)于該描述其它類型還可能是：

_thread_uninitialized：
線程還沒有創(chuàng)建，它只在內(nèi)存原因崩潰的時候才出現(xiàn)
_thread_new：
線程已經(jīng)被創(chuàng)建，但是還沒有啟動
_thread_in_native：
線程正在執(zhí)行本地代碼，一般這種情況很可能是本地代碼有問題
_thread_in_vm：
線程正在執(zhí)行虛擬機代碼
_thread_in_Java：
線程正在執(zhí)行解釋或者編譯后的Java代碼
_thread_blocked：
線程處于阻塞狀態(tài)
…_trans：
以_trans結(jié)尾，線程正處于要切換到其它狀態(tài)的中間狀態(tài)

最后的“id=56005”表示線程ID，stack(0x00002b5e1aa2a000,0x00002b5e1ab2b000)表示棧區(qū)間。“siginfo:si_signo=SIGBUS: si_errno=0, si_code=2 (BUS_ADRERR), si_addr=0x00002b5de3cda000”這部分是導(dǎo)致虛擬機終止的非預(yù)期的信號信息：其中si_errno和si_code是Linux下用來鑒別異常的，Windows下是一個ExceptionCode。

上圖為棧頂程序計數(shù)器旁的操作碼，它們可以被反匯編成系統(tǒng)崩潰前執(zhí)行的指令。

上圖為線程棧信息。包含了地址、棧頂、棧計數(shù)器和線程尚未使用的棧信息。到這里就基本上已經(jīng)確定了問題所在原因了。

全量線程信息

所有線程信息，其中_thread_blocked表示阻塞。

安全點和鎖信息

虛擬機狀態(tài)。not at safepoint 表示正常運行。其余狀態(tài)：- at safepoint：所有線程都因為虛擬機等待狀態(tài)而阻塞，等待一個虛擬機操作完成；- synchronizing：一個特殊的虛擬機操作，要求虛擬機內(nèi)的其它線程保持等待狀態(tài)。

虛擬機的 Mutex 和 Monito r目前沒有被線程持有。Mutex 是虛擬機內(nèi)部的鎖，而 Monitor 則關(guān)聯(lián)到了 Java 對象。

堆信息

新生代、老年代、持久代空間間一目了然。

本地代碼緩存

一塊用于編譯和保存本地代碼的內(nèi)存。

編譯事件

記錄10次編譯事件。

gc相關(guān)記錄

記錄10次 JVM堆GC情況。

jvm內(nèi)存映射

這些信息是虛擬機崩潰時的虛擬內(nèi)存列表區(qū)域。它可以告訴你崩潰時哪些類庫正在被使用，位置在哪里，還有堆棧和守護頁信息。

00400000-00401000：內(nèi)存區(qū)域
r-xp：權(quán)限，r/w/x/p/s分別表示讀/寫/執(zhí)行/私有/共享
00000000：文件內(nèi)的偏移量
c7:427a：文件位置的majorID和minorID
2130：索引節(jié)點號
/weblogic/jdk1.7.0_141/bin/java：文件位置
jvm啟動參數(shù)

jvm 虛擬機參數(shù)和環(huán)境變量信息。

服務(wù)器信息

服務(wù)器CPU、MEM相關(guān)信息。

至此，一份JVM Crash日志就拆解完了，觸發(fā)致命錯誤的操作異常或者信號信息，版本和配置信息，觸發(fā)致命異常的線程詳細(xì)信息和線程棧，當(dāng)前運行的線程列表和它們的狀態(tài)，堆信息，加載的本地庫信息，JVM參數(shù)信息，操作系統(tǒng) C信息……可以看到日志信息豐富、詳盡。了解和掌握Crash日志內(nèi)容了，那么此類問題追因溯源，自然也就得心應(yīng)手了。