解密JVM崩潰(Crash):如何通過日志分析揭開神秘面紗
一、前言
當使用Java來構建一個復雜的軟件系統時,系統偶發性崩潰(也會被稱為Crash)是一個不小的挑戰。這種情況不出現則已,一出現可能會對系統的穩定性和可靠性產生相當大的負面影響,同時也會給終端用戶帶來不良體驗。在本文中,我們將基于崩潰的現場進行深入探討以及如何通過技術手段來識別、調試和解決這些問題。同時我們將深入研究如何利用現代開發工具和最佳實踐來減少系統崩潰的可能性,進而提高系統的穩定性和可靠性。
二、什么是崩潰?
簡而言之,就是我們常說的 - 系統掛了,進程消失了。
當發生一般的問題情況時,研發人員就像是消防員一樣,需要火速趕到現場,分析日志,檢查堆棧,然后試圖重現并解決問題。這個過程就像一場緊急救援任務,需要迅速、果斷的行動,同時也需要謹慎對待,以避免引入更多問題。
但偶發性崩潰會更難處理。因為系統留給我們可用于排查的信息并不夠多,甚至于重啟后這樣的崩潰再也不會發生。這個解決問題的過程就像是一場復雜的推理游戲,需要耐心和技巧。幸運的是,虛擬機還是給我們留下了一點蛛絲馬跡供我們來進行深入的定位和跟蹤。
三、一個例子
為了更進一步深入的探尋虛擬機崩潰背后的細節,我嘗試給出一段異常代碼:
import sun.misc.Unsafe;
import java.lang.reflect.Field;
public class Crash {
public static void main(String[] args) throws NoSuchFieldException, IllegalAccessException {
Field unsafeField = Unsafe.class.getDeclaredField("theUnsafe");
unsafeField.setAccessible(true);
Unsafe unsafe = (Unsafe) unsafeField.get(null);
unsafe.getInt(-1);
}
}
Unsafe類是一種非常強大且危險的工具,它提供了直接操作內存和執行低級別代碼的能力。這個類通常被用于開發高性能的并發框架和底層操作系統相關的功能。由于使用Unsafe類可以繞過Java語言的一些安全檢查,因此需要非常小心地使用,否則可能會導致嚴重的內存錯誤和安全漏洞。如上代碼所示,我們嘗試在一個非法的內存區域讀取數據。當執行完成后我們立刻會在控制臺看到如下輸出:
好了,我們的程序此刻已經崩潰了。虛擬機在也在崩潰的控制臺日志清楚的提示我們“A fatal error has been detected by the Java Runtime Environment.”
四、崩潰日志詳解
上述控制臺日志只是對于當前虛擬機崩潰的一個概要說明。在崩潰時虛擬機會幫我們生成兩份日志文件。一份是進程的coredump文件,由操作系統負責生成;另一份是Java虛擬機自己在崩潰時生成。這兩部分日志對我們問題的排查都有極大的作用。這里我們著重介紹Java虛擬機生成的這部分日志的細節。
文件路徑
當Java程序崩潰時,默認情況下會在當前進程運行目錄來生成形如hs_err_pid%p.log
的文件。這里的%p
為通配符,系統會自動轉化為當前的進程PID。例如Java進程編號為1941生成的文件名即為hs_err_pid1941.log
。同時,虛擬機還提供了-XX:ErrorFile
選項來幫助我們自定義文件的生成位置。比如我們想要把文件存儲到系統任意指定目錄下,可以指定啟動參數形如:-XX:ErrorFile=/home/admin/hs_err_pid%p.log
。需要注意的是,如果由于一些異常原因在工作目錄無法存儲(比如寫入權限不足),則該文件會被存儲在操作系統的臨時目錄下。在Linux操作系統環境下,這個地址是/tmp
。
信息概要
崩潰日志包含在系統崩潰發生時獲取到的相關信息,具體包括如下(包括但不限于):
- 導致進程崩潰的操作異常或信號
- 版本和配置信息
- 導致進程崩潰的線程的詳細信息和線程的堆棧跟蹤
- 正在運行的線程列表及其狀態
- 關于堆的摘要信息
- 加載的本地庫列表
- 命令行參數
- 環境變量
- 關于操作系統和CPU的詳細信息
而在Java虛擬機崩潰時,生產的崩潰日志文件默認會分為4大部分內容:
- 提供崩潰簡要描述的頭部信息
- 線程信息
- 進程信息
- 系統信息
為了方便查閱,以下的章節中,我在認為相對關鍵的地方都打上了星號(※),用來表示該小節內容在問題排查時要多留意,是日志能給出線索的相對高發地點。
頭部信息
一個示例:虛擬機收到意外信號發生崩潰
如上所示,崩潰日志的開始部分其實就是我們在控制臺剛才看到的那部分內容,崩潰日志文件的頭部用簡明扼要的方式描述了Java進程崩潰的根本原因。在這個區域我們暫時只需要關心3個信息。
※ 崩潰原因
崩潰的具體原因可見圖中第二行,這里一般會給出系統崩潰的原因。我們可以簡單的分析為下圖:
SIGSEGV (0xb) at pc=0x417789d7, pid=21139, tid=1024
| | | | +--- 線程ID
| | | +------------- 進程ID
| | +--------------------------- 程序計數器
| +--------------------------------------- 信號編號
+---------------------------------------------- 信號名稱
這里有三個信息極為重要:信號名稱、程序計數器、線程ID。它會是我們后續排查問題用到的前置信息,在此先按下不表,下文中會陸續說明。
※ 問題幀棧
第二個關鍵的點是出問題的幀棧,這等于是告訴了我們代碼是運行在什么地方觸發了上面的崩潰原因。比如下方的示例,我們可以看到是執行到了虛擬機內部代碼(用大寫字母V來表示)的函數Unsafe_GetNativeInt進而觸發了系統崩潰。
# Problematic frame:
# V [libjvm.so+0xa6d702] Unsafe_GetNativeInt+0x52
棧幀(frame)表示程序運行時函數調用棧中的某一幀。簡單來說可以理解為調用某個方法。
這里幀棧前面的大寫字母也有特定含義。
※ 核心轉儲文件
頭部信息里有一句話也很重要。
這意味著進程在崩潰的時候順便幫我們生成了核心轉儲文件(coredump)。關于核心轉儲文件,它是操作系統在進程收到某些信號而終止運行時,將此時進程地址空間的內容以及有關進程狀態的其他信息寫入一個磁盤文件。相比Java本身的崩潰文件,他后續還可以使用諸如gdb的工具進行調試。核心轉儲文件對于問題調試還是非常有用的:
- 完整性和全局視角:操作系統的coredump包含了整個進程的內存轉儲,包括了JVM 本身的內存以及 JVM 進程所依賴的操作系統資源的狀態。這提供了更全面的視角,有助于診斷問題的根源。
- 內存信息:操作系統的coredump包含了進程的完整內存鏡像,包括了堆和棧的信息,這對于分析內存狀態以及發現內存相關的問題非常重要。
- 操作系統資源狀態:coredump還可以提供操作系統級別的資源狀態信息,例如打開的文件、網絡連接等。這些信息可以幫助診斷和解決一些與操作系統資源相關的問題。
- 與調試器的兼容性:一些調試器可能更喜歡使用操作系統的coredump進行分析和調試。在某些情況下,使用coredump可能更容易進行深入的調試和分析。
線程信息
這部分包含了剛剛崩潰的線程的信息,大部分情況下,這里是我們需要核心關注的點。虛擬機從線程視角清晰的描繪了當系統崩潰的那一時刻的數據情況。
※ 線程概要
虛擬機開門見山的給出了線程的基本信息。我們可以用下方的圖示來簡要說明:
7feed0009800 JavaThread "main" [_thread_in_vm, id=37696, stack]
| | | | | +--------- 線程棧的范圍
| | | | +----------------- 線程ID
| | | +----------------------------- 線程狀態(僅限Java線程)
| | +------------------------------------------- name(線程名稱)
| +---------------------------------------------------- type(線程類型)
+-------------------------------------------------------------- pointer(線程內存指針)
上述線程信息我們可以主動先嘗試忽略部分內容(比如線程內存指針是指向虛擬機內部線程結構的指針,大部分情況下我們排查問題都用不到),我們這里可以優先關注2個內容,以上圖為例:
※ 線程類型
如上圖所示,我們的線程類型是JavaThread
。在Hotspot虛擬機中,線程的類型有很多種:
JavaThread
VMThread
CompilerThread
GCTaskThread
WatcherThread
ConcurrentMarkSweepThread
JvmtiAgentThread
ServiceThread
CodeCacheSweeperThread
- ...
它們有的負責Java代碼的編譯、有的負責GC的執行、有的負責緩存的清理,最終各司其職完成了虛擬機內部的各種操作。上述例子中的JavaThread
我們暫時可以認為他是一個標準的Java代碼啟動的線程。
※ 線程狀態
上述信息里還有一個關鍵信息是_thread_in_vm
,它表示了線程當前所處的狀態。
這些狀態基本上和我們熟知的線程狀態所對應。在一些比較極限的場景下,還會有一些瞬時的“中轉”狀態。
Hotspot虛擬機在這里將線程的狀態劃分的更為清楚,便于技術人員第一時間知道線程到底處于一種什么樣的狀態下,進而可以更快速的定位到具體的問題。
※ 信號量概要
接下來,虛擬機在這里描述了導致進程終止的意外信號。
在本文的示例中,異常碼是11,它對應的信號量是SIGSEGV
,這是崩潰時最為常見的一種信號量,意味著當前進程正在從非法內存值讀取內容(si_addr)。簡單來說,每個進程所能讀寫的內存是有一定范圍的,如果超出這個范圍進行內存讀寫是會被操作系統認為是非法的操作。SIGSEGV
同時下面有2種不同的si_code,分別是SEGV_MAPERR
(未映射的地址)、SEGV_ACCERR
(無效的訪問許可)。
我們知道了信號量的概念后,再聊點題外話,SIGSEGV
的本質是內存的非法訪問,這其實是非常嚴重的錯誤。所以很多語言碰到類似問題會默認讓系統崩潰(因為非法訪問的后果誰也不知道,所以干脆崩了算了避免更意外的情況),Java虛擬機當然也遵從了這個約定。但是在Java虛擬機內部,有兩種特殊的場景本質也是內存非法訪問且接收到了SIGSEGV
,但系統并沒有崩潰且還能繼續運行:
NullPointerException
StackoverflowError
這種例外情況我們需要特殊說明。我們先來看看一個標準的SIGSEGV
信號到來時進程的時序:
- 進程正常執行指令
- 內存非法訪問
- 進程收到操作系統發來的SIGSEGV信號量
- 若進程注冊了信號回調函數,則執行,否則默認結束進程
上面的關鍵就在最后的回調函數。如果進程主動注冊了信號回調函數,則可以在注冊的函數內部選擇性的忽略指定信號(這樣系統就不會掛了),來提升整體的代碼穩定性和健壯性。Java虛擬機內部的處理源碼感興趣的可以見下方:
==================== os_linux_x86.cpp ====================
extern "C" JNIEXPORT int
JVM_handle_linux_signal(int sig,
siginfo_t* info,
void* ucVoid,
int abort_if_unrecognized) {
// 這里處理StackoverflowError的情況
// Handle ALL stack overflow variations here
if (sig == SIGSEGV) {
address addr = (address) info->si_addr;
// check if fault address is within thread stack
if (thread->on_local_stack(addr)) {
// stack overflow
if (thread->in_stack_yellow_reserved_zone(addr)) {
if (thread->thread_state() == _thread_in_Java) {
if (thread->in_stack_reserved_zone(addr)) {
frame fr;
if (os::Linux::get_frame_at_stack_banging_point(thread, uc, &fr)) {
assert(fr.is_java_frame(), "Must be a Java frame");
frame activation =
SharedRuntime::look_for_reserved_stack_annotated_method(thread, fr);
if (activation.sp() != NULL) {
thread->disable_stack_reserved_zone();
if (activation.is_interpreted_frame()) {
thread->set_reserved_stack_activation((address)(
activation.fp() + frame::interpreter_frame_initial_sp_offset));
} else {
thread->set_reserved_stack_activation((address)activation.unextended_sp());
}
return 1;
}
}
}
// Throw a stack overflow exception. Guard pages will be reenabled
// while unwinding the stack.
thread->disable_stack_yellow_reserved_zone();
stub = SharedRuntime::continuation_for_implicit_exception(thread, pc, SharedRuntime::STACK_OVERFLOW);
} else {
// Thread was in the vm or native code. Return and try to finish.
thread->disable_stack_yellow_reserved_zone();
return 1;
}
} else if (thread->in_stack_red_zone(addr)) {
// Fatal red zone violation. Disable the guard pages and fall through
// to handle_unexpected_exception way down below.
thread->disable_stack_red_zone();
tty->print_raw_cr("An irrecoverable stack overflow has occurred.");
// This is a likely cause, but hard to verify. Let's just print
// it as a hint.
tty->print_raw_cr("Please check if any of your loaded .so files has "
"enabled executable stack (see man page execstack(8))");
} else {
// Accessing stack address below sp may cause SEGV if current
// thread has MAP_GROWSDOWN stack. This should only happen when
// current thread was created by user code with MAP_GROWSDOWN flag
// and then attached to VM. See notes in os_linux.cpp.
if (thread->osthread()->expanding_stack() == 0) {
thread->osthread()->set_expanding_stack();
if (os::Linux::manually_expand_stack(thread, addr)) {
thread->osthread()->clear_expanding_stack();
return 1;
}
thread->osthread()->clear_expanding_stack();
} else {
fatal("recursive segv. expanding stack.");
}
}
}
}
......
// 這里處理NullPointerException的情況
if (sig == SIGSEGV &&
!MacroAssembler::needs_explicit_null_check((intptr_t)info->si_addr)) {
// Determination of interpreter/vtable stub/compiled code null exception
stub = SharedRuntime::continuation_for_implicit_exception(thread, pc, SharedRuntime::IMPLICIT_NULL);
}
}
}
...
// StackoverflowError和NullPointerException會主動返回并被記錄, 系統不掛
if (stub != NULL) {
// save all thread context in case we need to restore it
if (thread != NULL) thread->set_saved_exception_pc(pc);
os::Linux::ucontext_set_pc(uc, stub);
return true;
}
...
// 虛擬機不主動處理的信號到達這里會觸發系統掛掉
VMError::report_and_die(t, sig, pc, info, ucVoid);
ShouldNotReachHere();
return true; // Mute compiler
}
※ 寄存器
錯誤日志中的下一個信息顯示了致命錯誤發生時的寄存器上下文。這個輸出的確切格式取決于處理器。當與[指令上下文]這一節結合來看時,寄存器的數值可能會很有用。在當前基本都是x86-64的架構下,寄存器的簡單描述如下:
但我們這里如果單純記每個寄存器的作用的話未免過于枯燥和乏味,我們需要的是找到系統崩潰的原因。除了和指令結合使用,這里也可以優先關注下通用寄存器中的內存值,很多時候是個初步的突破口。
以上圖為例,64位操作系統下用戶空間地址范圍為[0-0x00007FFFFFFFF000],我們對照上述寄存器內的數據來看很快便發現R12寄存器的地址是0xffffffffffffffff
。這顯然不是一個合法的地址,從而也進一步的印證了日志開頭給出的SIGSEGV
錯誤。
棧地址
進一步的,虛擬機給出了出問題的線程的幀棧地址數據,如果不考慮后面的core文件分析的情況下,大多數場景下這些密密麻麻的字符對我們來說可參考的意義并不大,可以簡短了解即可。
- 虛擬機給出了sp指針指向的地址,這會和上面的rsp寄存器(棧頂)位置對應。
- X86-64的機器上,每一行對應了16個字節,后續兩列每一列的內容16進制輸出。
※ 指令上下文
指令上下文輸出了出問題前后的64字節的操作碼。這在一些比較難以排查的問題場景下還是很有極大作用的。簡單來說,雖然我們處在Java的語言環境里,但和操作系統的背后交互其實還是一條條毫無感情的機器碼。而上述地址對應的指令數據就是背后要執行的機器碼。但因為機器碼過于晦澀,我們的前人才搞出了匯編語言這么個東西讓開發的過程變得不那么繁瑣。而這些操作碼可以通過反匯編器進行解碼,以生成崩潰位置附近的指令。
上述pc地址對應的匯編是(網上有很多在線反匯編解碼工具):
0x00007faaf1397702: 45 8B 24 24 mov r12d, dword ptr [r12]
0x00007faaf1397706: C6 80 3C 03 00 00 00 mov byte ptr [rax + 0x33c], 0
0x00007faaf139770d: 48 8B 7B 50 mov rdi, qword ptr [rbx + 0x50]
由于我們已經已知R12的地址有問題,無法讀取自己管控內存地址之外的數據。所以我們很快可以初步判定是這一行匯編的問題:mov r12d, dword ptr [r12]
。它的含義是從R12寄存器取雙字讀取32位的值,然后保存在R12寄存器的低位中。在結合上下文函數幀知道出錯的地方是unsafe的getInt方法,而getInt方法的入參的含義本身就需要傳入準確的地址信息,那么這個問題的答案就基本已經付出水面了。
※ 寄存器內容
這部分可以看做是對于之前的寄存器那一節的具體說明。之前相對晦澀的地址,在這里虛擬機給出了當前地址代表的具體內容,以截圖為例:
- RAX、RBX、R15是線程
- RCX、R11指向動態鏈接庫中
- RDX、RSP、RBP、R14均指向線程中
- R8、R13指向某個具體方法
- R10指向解釋模式中的某個代碼片段
- RSI、RDI、R9、R12均指向一個未知的值(an unknown value)
這里還是要說明,未知的值并不一定是問題,但是如果地址本身就是一個非法地址則是需要重點關注的事情。
※ 幀棧明細
按照順序,接下來的輸出是線程幀棧的細節,如上所示。
首先給出的是問題棧的區間和棧頂地址以及剩余的空間,接著,如果可能的話會打印堆棧幀且最多打印 100 個幀。對于 C/C++ 幀,可能還會打印庫名稱。
然后為了更清楚的看到調用幀的明細,虛擬機把這里的內容分成了兩部分:
- Native frames
- Java frames
簡單來說他們的區別是Native幀沒有考慮到由運行時編譯器內聯的Java方法,而Java幀會考慮內聯。同時Native幀會打印線程的所有函數調用,相對Java幀會更詳細。
進程信息
※ 進程里的線程
首先映入眼簾的是進程內的線程信息,這里展示了虛擬機內部的Java線程以及其它線程信息。特別需要注意的是“=>”這個符號,它標識了哪個線程是當前的線程。
具體線程的描述過程在線程信息這一節已經說過,在此不做贅述。
※ 虛擬機安全狀態
接下來的內容是虛擬機的安全點狀態信息。注意這里的狀態描述 not at safepoint
。
這里的虛擬機狀態可分為3種情況:
- not at safepoint (正常情況)
- at safepoint (所有線程處于安全點等待VM進行一些重要的操作。如GC、Debug等)
- synchronizing (這是個一個瞬時的狀態。VM等待所有線程到達safepoint,已經達到safepoint的線程會掛起)
很自然的,如果你看到這里的VM state顯示的如果是at safepoint,那就要稍微留意一下和GC相關的細節(雖然safepoint并不代表一定有GC)。關于safepoint更多的細節,可見之前我寫的一篇文章Java程序陷入時間裂縫:探索代碼深處的神秘停頓|得物技術
鎖&監視器
接下來,虛擬機給出了當前線程擁有的互斥鎖Mutex
和監視器Monitor
列表。特別需要注意的是:這些互斥鎖和監視器是虛擬機內部的鎖和監視器,而不是與Java對象相關的鎖和監視器。所以絕大多數的崩潰文件下,這里的輸出都是None。
※ 內存使用摘要
這里是虛擬機堆區的內容,對于Java程序員來說,這塊內容看著就熟悉多了。我們逐一來分析看看。
內存基礎模型
- heap address: 0x00000006c0000000
- size: 4096 MB
這里交代了內存的基本信息,heap address
說明了當前我們進程的虛擬內存地址的起始地址。而size
則表示當前進程預留(申請)了多大的內存,如圖所示為4096MB,即4G。這些信息得記下來,如果遇到諸如物理內存不足的問題,這些都是關鍵的上下文信息。
- Compressed Oops mode: Zero based
- Oop shift amount: 3
這里的 Compressed Oops mode
稍微有點難懂,它表示了虛擬機在內部對于對象的壓縮模式(也稱之為壓縮指針技術)。在32位系統上,對象指針通常占用4個字節(32位),而在64位系統上,對象指針通常需要8個字節(64位)。這意味著在64位系統上,對象指針的大小會比在32位系統上大。但因為我們現在基本上都在使用64位的系統,為了節省內存空間,JVM引入了壓縮指針技術。這種技術通過在64位系統上使用更小的指針來表示對象的引用,從而減小了對象指針的大小。在壓縮指針模式下,JVM會將對象指針壓縮為32位,然后通過一些額外的計算來還原成對應的64位地址。在大內存服務場景下,帶來的收益會相當可觀。然后在Hotspot內部定義了四種模式分為四種
UnscaledNarrowOop(32位)、ZeroBasedNarrowOop(無基址的32位壓縮)、DisjointBaseNarrowOop(分離基址壓縮指針)、HeapBasedNarrowOop(指定基地址的32位壓縮,可以用-XX:HeapBaseMinAddress來指定)。可以看到我們系統默認時會使用壓縮指針來完成空間的節省。
再來看看Oop shift amount
,它實際上代表了內存對象壓縮的偏移算法。在講這個之前要提一下當前Hotspot虛擬機的一個重要基礎:HotSpot虛擬機的內存模型要求對象起始地址和對象大小必須是8字節的整數倍,換句話說就是任何對象的大小都必須是8字節的整數倍,如果大小不足會強制填充(向上對齊)到8字節的整數倍。比如一個對象實際大小為12字節,那么實際在Hotspot內部存儲會被對齊為16字節。這個基礎的前提極為重要,虛擬機內部的多處優化都是因為有這個內存限制的前提才得以進行。
我們繼續說回Oop shift amount
。它的值是3,虛擬機采用的對象壓縮方式是地址右移,所以它的根本意思就是內存需要右移3位來存儲,內存真正使用時按照左移3位來使用。由于對象和內存起始地址都是按照8字節對齊,所以內存地址的后3位必然是0,該過程不會丟失任何信息。所以一個完整的內存換算公式如下所示:
<narrow-oop-base> + (<narrow-oop> << 3) + <field-offset>
以上述截圖中的地址0x00000006c02bb8e8來舉例,它實際經過壓縮后在虛擬機內部存儲的地址是
0 + (0x00000006c02bb8e8<<<3) = 0xd805771d。
- Narrow klass base: 0x0000000000000000
- Narrow klass shift: 3
和之前類似,只不過前面說的是對象,這里說的是klass(類的元數據)。和對象相比,元數據的基地址默認從0開始,存儲位置位于我們熟知的Metaspace空間內。其他語義類似,在此不做贅述。
- Compressed class space size: 1073741824
- Address: 0x00000007c0000000
繼續看細節。這里的 Compressed class space size
便是我們熟悉的Metaspace區域大大小。這里的1073741824換算過來就是1GB。這也是未配置該區域大小時Hotspot給出的默認值。Address代表了Metaspace的大小是從內存地址0x00000007c0000000開始。
內存使用明細
這里虛擬機描述的很清楚了,大多數信息不用解釋大家也看的明白。這里唯一需要提一下的是這個內存邊界表達,比如from區域的內存被描述為[0x00000006c4450000, 0x00000006c4450000, 0x00000006c4cd0000)。它的含義是內存區域從0x00000006c4450000開始,到0x00000006c4cd0000結束,0x00000006c4450000是當前已使用的標記位置。大多數情況下,如果下次有內存分配將會從0x00000006c4450000處開始繼續分配。但需要注意的是,我的示例采用了cms垃圾回收,如果采用g1模型,那這塊內容的輸出會稍有不同。
雖然這個圖描述的已經足夠清晰,但是我還是畫一個圖來描述下上述內存區域的具體使用情況,會更直觀:
GC輔助模型
這里的內容依然和GC相關,但對于問題的排查相關性都不大,在這里只簡單說明下卡表(Card table byte_map):
卡表是一個標準的空間換時間的解決方案。卡表通常在 JVM 中實現為單字節數組。當我們把 JVM 劃分成不同區域的時候,每一個區域(通常是4k字節)就得到了一個標志位。每一位為 1 的時候,表明這個區域為 dirty,持有新生代對象,否則這個區域不持有新生代對象。這樣,新生代垃圾收集器在收集live set 的時候,可以通過以下兩個操作:
- 從棧/方法區出發,進入新生代掃描。
- 從棧/方法區出發,進入老年代掃描,且只掃描 dirty 的區域,略過其他區域。
polling page
這里的Polling page其實對我們的問題排查并無多大意義,但確實是一個有意思的知識點,它和我們熟知的JIT下的GC有關系。簡單來說:
- JIT下虛擬機在指定代碼位置完成安全點代碼的放置,代碼的內容是讀取一小塊內存(就是這里的polling page)
- GC時設置這塊內存不可讀
- 其他線程代碼運行到安全點發現代碼不可讀,操作系統層面拋出SIGSEGV信號
- 虛擬機在啟動是就完成SIGSEGV信號注冊,來監聽本次SIGSEGV的內存代碼是否是polling page位置
- 如果是,進程不終止,當前線程進入安全點,線程掛起為后續GC做準備
可以看到,一個很細小的功能,虛擬機也是花費了很大精力,這里回頭可以總結一篇文章來深入聊聊。
CodeCache
關于CodeCache是什么這里就不多做贅述。這里稍微解釋下日志里出現的部分內容。
首先日志給出了整個CodeCahe的使用情況,第一行給出了總大小(245760kb),已使用(1080kb),空閑(244679kb)。第二行用更直觀的方式給出了內存上下界(bounds)。以上圖為例,這里的0x00007faadcbc0000代表了CodeCache內存區域的下界,對應的0x00007faaebbc0000則是內存上界,0x00007faadce30000代表的是已使用內存的邊界(可以理解這個邊界就是已使用的指針)。
CodeCache內部本質上是各種大小不一的內存塊。有的是方法經由JIT編譯后的代碼,有的是動態生成的元數據等等。當前系統一共有253個內存塊,其中10個JIT編譯過的方法,以及160個adapters。這些adapters其實是虛擬機內部在解釋模式和編譯模式下的一種適配,所有方法的默認入口都是解釋模式,虛擬機內部會判斷當前方法是否已經編譯過了,如果已編譯則基于adapter路由到已編譯的方法,否則繼續解釋執行。整體如下圖所示。
事件分析
※ 編譯事件(Compilation events)
Compilation events 顯示了最近10次從Java字節碼編譯為機器碼的方法。這里有一個需要關注的點:如果你的機器多次崩潰看到的編譯事件都相同,可能意味著JVM正在錯誤的編譯當前方法。如果不明白為何虛擬機會出現這種錯誤,你可以嘗試重寫方法將其簡化、拆分等,這將有助于你避免相關的崩潰問題?;蛘咭部梢岳锰摂M機提供的命令來禁止指定方法的編譯,比如:
-XX:CompileCommand="exclude java.util.ArrayList::add"
GC歷史事件(GC Heap History)
這里列舉出了系統在崩潰時出現的近10次GC。這里的堆的輸出模型和之前章節講述的模型類似,在此就不再做過多說明。
※ 逆優化事件(Deoptimization events)
關于逆優化簡而言之,就是JIT基于特定條件和假設完成代碼編譯后,在一些場景下,虛擬機突然發現當前的特定條件和假設不滿足,當前編譯好的方法如果繼續執行會發生一些意料之外的情況,此時虛擬機就會觸發自動逆優化,針對已經編譯好的方法做特定處理,確保整體運行準確。
我們來簡單基于日志分析下當前的事件內容:
首先能看到的是觸發本次逆優化的原因(reason
),在Hotspot虛擬機內部可能的共有32種。限于篇幅我們不可能全部拿出來在這里進行說明,我們可以選一些有代表性的:
- Reason_null_check(虛擬機看到了預期之外的null值)
- Reason_range_check(虛擬機看到了預期之外的數組下標)
- Reason_class_check(虛擬機看到了預期之外的對象類型)
- Reason_unstable_if(分支預測失效,比如一個if始終返回false,突然一次返回了true)
其次我們看到的是Hotspot對于這些觸發的場景的針對動作(action
),一共5種:
- Action_none(直接切換到之前的解釋模式執行方法,保留之前JIT編譯好的方法)
- Action_maybe_recompile(JIT重新編譯當前方法)
- Action_reinterpret(臨時切回解釋模式執行方法,廢棄之前JIT編譯的方法然后內部再決策是否需要重新編譯)
- Action_make_not_entrant(JIT立即重新編譯且廢棄之前JIT編譯好的方法,下次調用就會使用新的編譯結果)
- Action_make_not_compilable(直接切換到之前的解釋模式執行方法,廢棄之前JIT編譯好的方法且不再編譯)
可以看到虛擬機基于不同的逆優化給出了各種解決方案,確保程序的正常運行。
最后,method給出了具體涉及本次逆優化的方法,如上圖所示的"java.util.Matcher.match()" 。
和前文所說的編譯事件(Compilation events)類似,如果你的機器多次崩潰看到的逆優化事件都相同,可能意味著JVM正在錯誤的逆優化當前方法。對應的解決方案也是相同的:如果不明白為何虛擬機會出現這種錯誤,你可以嘗試重寫方法將其簡化、拆分或者使用指令-XX:CompileCommand
。
※ 類重定義事件(Classes redefined)
這里列舉出了當前Java進程中類被重定義(redefined
)的相關信息。上述時間可以簡單的理解為:Crash
這個類在應用啟動的第18.707秒被重新定義,當前類總計被重定義1次。這里有個小細節,java.lang.Class
中會保存一個類被重定義的次數到它的實例元數據中,可見java.lang.Class#classRedefinedCount
。
上面說的重定義是JDK5中引入的Instrument
接口提供的一種在運行時修改Java類文件的機制,以實現類的重新定義。我們熟知的Arhtas、Byteman、Greys、Skywalking、Pinpoint等都是基于Instrument
機制來完成了各種強大的監控功能。但盡管Instrument
接口當前已經被如此的廣泛運用,但它仍然存在一些潛在的問題和壞處:
- 難以調試:由于動態修改類文件會改變程序的行為,可能會導致調試困難,不利于排查問題。
- 兼容性問題:重新定義類可能會影響現有代碼的兼容性,導致原有功能無法正常運行。
- 不穩定性:對類進行重新定義可能會導致系統不穩定,產生意外的行為(如系統崩潰)。
因此,盡管Instrument
接口提供了強大的功能,但大多時候我們建議在生產環境使用時還需要慎重考慮,確保當前使用的組件足夠成熟,否則帶來的后果會非常嚴重。以我們常見的Arthas為例,導致線上應用崩潰的問題很常見:
內部異常事件(Internal exceptions)
這里透出了虛擬機內部的異常事件,這些事件包括了虛擬機內部的各種異常諸如生成OopMap的異常、jni調用相關的異常、虛擬機內部執行的逆優化問題、JIT相關的NPE等等等等。需要特別注意“內部”這兩個字。這意味著我們業務代碼層面的異常拋出是不會在這里出現的,所以這里我們可暫時無需過多關注。
通用事件(Events)
這里的日志輸出稍微有點迷惑,初看會給人一種所有事件匯總在一起的感覺。但這個區域實際的含義是:A log for generic messages that aren't well categorized。即通用未分類的事件內容都在這里,是個事件的大雜燴。包括但不限于如下場景:
- 類加載(如上圖所示)
- 新增線程
- GC后的內存整理
- 虛擬機線程執行重要的操作(VMOperation)
- JIT方法廢棄的內存清理
- ...
總之,這里依然是一個可以用來了解虛擬機在做什么事情,但是大多數情況對于我們問題的排查起不到太大作用的信息區域。
內存映射明細
這里其實就是當前進程在臨"死"前,pmap -d pid
命令輸出的結果。我們關注一些重要的列:
- [第1列]顯示內存區域的起始地址。每個區域代表進程的不同內存映射。
- [第2列]內存映射區域的訪問權限。這里的p代表的是(private)
- [第5列]指實際在內存中占用的字節數。
- [第6列]顯示內存區域的映射信息,通常包括文件名或其他標識符。如果是匿名內存(未映射到文件),則會顯示類似 [
heap
]、[stack
]、[anon
] 這樣的標識。
但在系統崩潰的情況下,當前內存映射明細大多時候都幫不上忙。但在排查內存泄漏問題時,內存映射的輸出還是很有用(如上所示利用pmap命令可以實時輸出),可以通過輸出看到是否有大段的連續內存占用、過多的匿名內存塊、異常的文件映射等等。
啟動參數&環境變量
Java進程的啟動參數以及系統環境變量,這里不過多展開。
信號處理
在信號量概要一節里有簡單聊過,虛擬機對于SIGSEGV
信號注冊了信號回調函數,這意味著當發生SIGSEGV內存異常方位,Java進程未必會崩潰結束。但實際上,虛擬機對于很多信號也注冊了回調函數,他們同樣的會在程序崩潰前再檢查一把是否需要殺掉進程,從而確保系統的整體穩定性。
系統信息
系統信息概要
這塊內容主要描述了操作系統的基本信息,包括系統相關信息,比如主機名、內核版本號、硬件架構等等。 輸出的內容基本可以和下列命令的含義相同。
cat /etc/os-release
uname -a
ldd --version
ulimit -a
w
如果是公司的機器的話,這塊不必過多關心。大多數情況出現問題我們要關注的是差異性問題,而公司一般會配有對應的SRE來管理應用配置,相關的配置也會有基線,相同應用的機器配置均會相同。
系統內存概括
這些內容其實就是系統崩潰瞬時cat /proc/meminfo
的輸出明細。/proc/meminfo
是了解Linux系統內存使用狀況的主要接口(需要注意的是在當前的MacOS開發環境并不適用),我們最常用的free
、vmstat
等命令就是通過它獲取數據的 ,但一般來說在排查一些內存泄漏問題,利用meminfo的輸出還是非常有幫助,但是遇到進程崩潰這種情況其實有幫助的信息不多,這里不做過多介紹。
CPU信息概況
這里其實就是命令cat /proc/cpuinfo
的輸出明細,給出了當前機器的CPU型號、CPU制造商、產品代號、主頻、二級緩存、浮點運算單元等信息,這些對于系統崩潰問題排查一般來說幫助不大,可以暫不關注。
其他信息
日志的結尾給出了內存,虛擬機版本等內容,但大多和之前重合,這里有一個有用的信息是elapsed time,它反映了從應用啟動到崩潰一共耗時多久(我的例子里直接啟動就主動讓虛擬機立刻崩潰了所以這里是0)。
五、core文件
好了,到這里我們介紹完了Java虛擬機提供的錯誤文件。但當Java虛擬機如上描述崩潰時,會同時生成在當前目錄生成一個叫core的文件。假設我的進程崩潰之前進程id為29296,那么core文件的名稱默認會是core.29296
(這里會根據用戶的個人配置不同文件名稱和路徑可能稍有差異)。這個core文件里記錄了程序在崩潰時的內存狀態,在有些時候崩潰文件不能給我們進一步信息的情況下,可以進一步的打開我們的思路,發現一些意想不到的結果。
分析core文件最常見的工具便是gdb。使用gdb打開core文件后常用的命令可以簡要介紹如下:
問題調用棧
bt
(backtrace)命令是
GDB
中用于查看當前調用堆棧的重要工具,可以說是問題排查的首要命令。通過當前命令,開發者可以顯示程序在崩潰或暫停時的函數調用歷史,了解執行狀態和調用關系。輸出包含每個函數的名稱、源文件及行號,以及參數信息,且從最近的調用開始逐步追溯。該命令還支持限制輸出的幀數(例如
bt 5
幀快照
當鎖定到第7個函數幀時,我們可以利用命令frame 7
來定位到這里。這表示我們已經切換到編號為7的調用幀。調用幀代表函數調用的上下文,我們后續可以進一步看到函數的參數、局部變量和調用位置等信息。進一步的我們輸入i r
(info registers的縮寫),代表我們需要查看此刻寄存器中的內容。自然的,我們會發現這里和之前Java虛擬機給出的錯誤日志的寄存器的每個值都相同。
為了更清楚的還原出問題的上下文,我們可以進一步探究:
- 第一行查看當前指令正在做什么操作,發現這和我們前文【指令上下文】中推出的結果是相同的!(這里需要注意匯編的語法有2種-INTEL和AT&T。gdb當前這里指AT&T語法,和上文中的格式稍有不同。)
- 第二行看下當前r12寄存器的地址(當然最開始的截圖已經有了)。
- 第三行嘗試范圍r12寄存器的地址對應的值,被提示內存無法訪問(和最開始的SIGSEGV對應)。
匯編代碼還原
對于更為復雜的問題,我們可能要深入到對應的C++層面的方法去深入探究(比如JIT編譯出了bug,編譯出了一個有問題的方法導致程序崩潰之類)。此時我們需要深入到指定方法的機器碼層面,此時基于gdb的調試可以利用disas命令完整還原出當前的匯編執行過程(如果我們當前的幀左邊有一個箭頭“=>”來表示)。
內存映射
最后介紹的指令是i proc m(是info proc mappings的縮寫)。這里輸出含義跟上面提到的【內存映射明細】 類似。就不過多贅述了,總之還是告訴了開發者內存的上下范圍界及其對應映射的文件在哪里。
六、一些經驗
虛擬機崩潰的原因分類
雖然系統崩潰的原因千奇百怪,但是大多數情況下,我們都可以將錯誤原因都可分為2種情況:
- 內存非法訪問
- 物理內存不足
內存非法訪問最為常見,如本文中介紹的例子就是這樣一種嚴重的錯誤情況。其次還有一種場景比較重要,那就是物理內存不足。當系統物理內存耗盡時它的錯誤原因大概長相如下圖所示:
物理內存不足系統崩潰虛擬機給出的原因及其解決方案
物理內存的崩潰類型相比內存非法訪問會更友好,它直接給出了研發可能的解決方案。
留意JNI
JNI(Java Native Interface)
是Java與C語言之間進行交互的重要機制,但進行有效的JNI編程并不簡單。開發者必須深入理解Java虛擬機的內部工作原理,以避免潛在的錯誤和問題。尤其是對于那些主要從事C語言開發的人員來說,缺乏對JVM原理的了解可能會導致程序在運行時出現意外的崩潰。
在之前的章節中,我們提到了NullPointerException的機制。其本質是虛擬機攔截SIGSEGV信號并拋出異常而不終止進程。然而,如果第三方C語言組件在沒有充分理解Java虛擬機的情況下,錯誤地注冊了SIGSEGV信號處理回調函數,那么在Java進程出現NullPointerException時,系統會因為SIGSEGV的回調被覆蓋導致進程崩潰。因此,在使用JNI時(包括應用依賴的第三方JNI組件),開發者必須特別注意,確保對JVM的工作原理有充分的認識,以維護系統的穩定性和可靠性。
敢于懷疑
Java虛擬機自身bug雖然相對概率小,但是在出現極端問題時也要適當考慮,畢竟大家都是人,寫個bug么在所難免。避免持續性的陷入bug自證的死結中。可以來https://bugs.openjdk.org/projects/JDK/issues/ 利用你崩潰時的關鍵字嘗試找找是否已經有人提出過類似的系統崩潰問題,有時候可能會事半功倍。
七、寫在最后
在深入探討JVM崩潰的各種細節及其解決方案后,我們可以看到,理解和掌握JVM的內在機制不僅對開發者至關重要,也對整個應用的穩定性和性能有著深遠的影響。通過合理的配置、監控工具的使用和適當的調優策略,我們可以有效地降低JVM崩潰的風險。
然而,面對復雜的系統,完全避免所有崩潰是困難的。關鍵在于具備快速診斷和恢復的能力,這要求我們在日常開發和運維中,持續關注系統的健康狀態,并及時進行故障排查。希望本文能夠為你在JVM的使用和維護上提供一些有價值的見解與幫助。