技術文章 » JVM致命錯誤紀錄檔詳解

JVM致命錯誤紀錄檔詳解

2023-06-02 09:00:19

目錄

這篇文章是我之前總結的一篇文章，因為整理部落格的原因，原有部落格已經登出，但這篇文章對一些讀者很有用，所以現在新瓶裝舊酒重新整理回來分享給大家。

最近一段時間生產環境頻繁出問題，每次都會生成一個hs_err_pid*.log檔案，因為工作內容的原因，在此之前並沒有瞭解過相關內容，趁此機會學習下，根據專案的使用情況，此文章針對JDK 8進行分析，不過因為素材問題，文章中參照的檔案內容為JDK 7生成的檔案，此處應該不影響，因為官方檔案中關於此部分說明使用的是JDK 6生成的檔案。我們將按照內容在檔案中出現的順序進行介紹。本人水平有限，工作中也沒有太多機會進行此類知識的應用，文章內容主要參考官方檔案，某些內容在官方檔案中並沒有涉及，相應的介紹也不一定準確，如果有不同看法可在評論區留言交流。

PS:本人水平有限，工作中也沒有太多機會進行此類知識的應用，文章內容絕大多數來自於官方檔案，某些內容在官網中並沒有涉及，相應的介紹不一定準確，希望各位大佬不吝賜教

JDK 8
官方檔案下載地址：https://www.oracle.com/java/technologies/javase-jdk8-doc-downloads.html
致命錯誤紀錄檔檔案：/docs/technotes/guides/troubleshoot/felog.html#fatal_error_log_vm

JDK 7
官方檔案地址：https://docs.oracle.com/javase/7/docs/
致命錯誤紀錄檔檔案：https://docs.oracle.com/javase/7/docs/webnotes/tsg/TSG-VM/html/felog.html

檔案描述

錯誤紀錄檔是在JVM遇到致命錯誤時生成的紀錄檔檔案，可能包括以下資訊：

  • 引發致命錯誤的異常操作或訊號
  • 版本和設定資訊
  • 引發致命錯誤的執行緒詳細資訊和執行緒堆疊記錄
  • 正在執行的執行緒及其狀態的列表
  • 有關堆的概要資訊
  • 載入的本機庫的列表
  • 命令列引數
  • 環境變數
  • 作業系統和 CPU 的詳細資訊

當問題嚴重到錯誤處理器無法收集並報告所有資訊時，可能只有一部分資訊會寫入錯誤紀錄檔。

檔案總共分為一下幾個章節：

  • 簡單描述崩潰資訊的檔案頭
  • 執行緒描述部分
  • 程序描述部分
  • 系統資訊部分

檔案位置

致命錯誤紀錄檔檔案位置可以通過 -XX:ErrorFile進行指定，例如：

java * -XX:ErrorFile=/var/log/java/java_error%p.log

以上設定表示檔案會放在/var/log/java目錄下，%p表示程序的PID。如果不設定XX:ErrorFile屬性，紀錄檔預設生成在執行java命令的目錄下，檔名預設為hs_err_pid%p.log，如果該目錄因為某種情況無法寫入（空間不足，許可權不足等），在linux系統下預設寫到/tmp目錄下，windows系統下預設使用環境變數中TMP對應的目錄，如果沒有則使用TEMP對應的目錄（TMP和TEMP均為windows預設的環境變數，且預設值一樣）。

檔案頭

檔案頭在錯誤紀錄檔的最開頭，主要是對問題的簡單描述。這部分內容同樣會列印到標準輸出，可能也會列印到應用程式的控制檯上。範例如下：

# 
# A fatal error has been detected by the Java Runtime Environment: 
# 
#  SIGSEGV (0xb) at pc=0x00007f80e0cd095c, pid=48, tid=140189843019520 
# 
# JRE version: Java(TM) SE Runtime Environment (7.0_80-b15) (build 1.7.0_80-b15)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode linux-amd64 compressed oops) 
# Problematic frame: 
# V  [libjvm.so+0x65395c]  jni_SetByteArrayRegion+0x19c 
# 
# Core dump written. Default location: /apps/gateway/project/bin/core or core.48
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp 
#

錯誤資訊記錄

前兩行主要描述了訊號型別、發起訊號的程式計數器、程序ID和執行緒ID，對應關係如下所示，鑑於瀏覽器和手機端顯示效果不一致，此處提供兩種方式：

#  SIGSEGV (0xb) at pc=0x00007f80e0cd095c, pid=48, tid=140189843019520
      |      |           |                    |       |
      |      |           |                    |       +--- 執行緒ID
      |      |           |                    +----------- 程序ID
      |      |           +-------------------------------- 程式計數器對應的指標
      |      +-------------------------------------------- 訊號值（十六進位制）
      +--------------------------------------------------- 訊號名稱
​紀錄檔內容 實際含義
SIGSEGV 訊號名稱
(0xb) 訊號值（十六進位制）
pc=0x00007f80e0cd095c 程式計數器對應的指標
pid=48 程序ID
tid=140189843019520 執行緒ID

訊號名稱是作業系統自身的一種資訊，CentOS 7下共有以下35種，可在/usr/include/bits/signum.h中檢視其具體的宣告

訊號名稱 訊號值 含義
SIGHUP 1 Hangup (POSIX).
SIGINT 2 Interrupt (ANSI).
SIGQUIT 3 Quit (POSIX).
SIGILL 4 Illegal instruction (ANSI).
SIGTRAP 5 Trace trap (POSIX).
SIGABRT 6 Abort (ANSI).
SIGIOT 6 IOT trap (4.2 BSD).
SIGBUS 7 BUS error (4.2 BSD).
SIGFPE 8 Floating-point exception (ANSI).
SIGKILL 9 Kill, unblockable (POSIX).
SIGUSR1 10 User-defined signal 1 (POSIX).
SIGSEGV 11 Segmentation violation (ANSI).
SIGUSR2 12 User-defined signal 2 (POSIX).
SIGPIPE 13 Broken pipe (POSIX).
SIGALRM 14 Alarm clock (POSIX).
SIGTERM 15 Termination (ANSI).
SIGSTKFLT 16 Stack fault.
SIGCLD SIGCHLD Same as SIGCHLD (System V).
SIGCHLD 17 Child status has changed (POSIX).
SIGCONT 18 Continue (POSIX).
SIGSTOP 19 Stop, unblockable (POSIX).
SIGTSTP 20 Keyboard stop (POSIX).
SIGTTIN 21 Background read from tty (POSIX).
SIGTTOU 22 Background write to tty (POSIX).
SIGURG 23 Urgent condition on socket (4.2 BSD).
SIGXCPU 24 CPU limit exceeded (4.2 BSD).
SIGXFSZ 25 File size limit exceeded (4.2 BSD).
SIGVTALRM 26 Virtual alarm clock (4.2 BSD).
SIGPROF 27 Profiling alarm clock (4.2 BSD).
SIGWINCH 28 Window size change (4.3 BSD, Sun).
SIGPOLL SIGIO Pollable event occurred (System V).
SIGIO 29 I/O now possible (4.2 BSD).
SIGPWR 30 Power failure restart (System V).
SIGSYS 31 Bad system call.
SIGUNUSED 31 -

JVM執行資訊

接下來兩行描述了JVM相關版本資訊及執行設定資訊，內容如下：

# JRE version: Java(TM) SE Runtime Environment (7.0_80-b15) (build 1.7.0_80-b15)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode linux-amd64 compressed oops)

上述檔案內容可以得知以下幾點：

  • JRE版本號為1.7u80
  • JVM版本號為24.80-b11
  • JVM執行在Server模式下。對應的是Client模式，Client JVM適合需要快速啟動和較小記憶體空間的應用，它適合互動性的應用，比如GUI；而Server JVM則是看重執行效率的應用的最佳選擇，更適合伺服器端應用。
  • JVM執行在混合模式下，即mixed mode，是JVM預設的執行模式。其他模式還有解釋模式（interpreted mode）和編譯模式（compiled mode），解釋模式會強制JVM以解釋方式執行所有的位元組碼，編譯模式下JVM在第一次使用時會把所有的位元組碼編譯成原生程式碼，這兩種模式各有優劣，單獨使用時都會有部分效能上的損失，所以預設使用混合模式即可，混合模式下對於位元組碼中多次被呼叫的部分，JVM會將其編譯成原生程式碼以提高執行效率；而被呼叫很少（甚至只有一次）的方法在解釋模式下會繼續執行，從而減少編譯和優化成本。

崩潰原因

接下來兩行描述了引發崩潰問題的函數幀

# Problematic frame:
# V  [libjvm.so+0x65395c]  jni_SetByteArrayRegion+0x19c
  |              |
  |              +-- 類似於程式計數器, 以庫名和偏移量表示。
  |                  對於與位置無關的庫(JVM和其他庫)，可以不通過
  |                  偵錯程式或通過反組合程式轉存偏移量周圍結
  |                  構的core檔案來定位引起崩潰的指令。
  +----------------- 幀型別

幀型別包括以下幾種：

幀型別 描述
C Native C frame
j Interpreted Java frame
V VMframe
v VMgenerated stub frame
J Other frame types, including compiled Java frames

關於例子中描述的jni_SetByteArrayRegion+0x19c這部分目前沒有找到相關的資料，官方給的範例中並沒有這一部分，根據字面含義來看，此部分應該表示的是崩潰時正在通過JNI方式呼叫SetByteArrayRegion方法。

錯誤資訊

接下來的錯誤資訊部分根據不同錯誤顯示不一樣的內容，在官方給的資料中提供了一份關於內部錯誤的錯誤資訊，範例如下：

# An unexpected error has been detected by HotSpot Virtual Machine:
# Internal Error (4F533F4C494E55583F491418160E43505000F5), pid=10226, tid=16384
# Java VM: Java HotSpot(TM) Client VM (1.6.0-rc-b63 mixed mode)

以上範例中提供的內容沒有訊號名稱和訊號值，只包含了Internal Error和一個十六進位制的字串，該字串對出現問題的模組和行號進行了編碼，通常情況下只對JVM工程師有用。

因為我們生產環境上出現的問題和範例中的問題種類不一樣，所以我們拿到了這樣一段資訊：

# Core dump written. Default location: /apps/gateway/project/bin/core or core.48
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp

這段資訊中記錄了core dump檔案的位置和官方的BUG反饋頁面地址，針對具體問題則需要檢視core dump檔案了。

執行緒描述

這一部分描述崩潰時正在執行的執行緒資訊，如果有多個執行緒同時崩潰，只會列印其中一個執行緒的資訊。

執行緒資訊

Current thread (0x00007f80dc8ce000):  JavaThread "RcvThread: com.*.*.*.remote.internal.RemoteTCPConnection[qmid=*,fap=10,peer=/*.*.*.9,localport=*,ssl=no]" daemon [_thread_in_native_trans, id=90,stack(0x00007f807dbb5000,0x00007f807dcb6000)]

第一部分展示了引發致命錯誤的執行緒，以上為生產的實際資訊，因為敏感資訊，內容中部分欄位使用*進行了脫敏。各部分說明如下：

​紀錄檔內容 實際含義
(0x0805ac88) 指標地址
JavaThread 執行緒型別
main 執行緒方法名
_thread_in_native 執行緒狀態
id=21139 執行緒ID
stack(0x7dbb5000, 0x7dcb6000) 棧區間 
Current thread (0x0805ac88):  JavaThread "main" [_thread_in_native, id=21139, stack(0x7dbb5000, 0x7dcb6000)]
                    |             |         |            |          |            |
                    |             |         |            |          |            +--------- 棧區間
                    |             |         |            |          +---------------------- ID
                    |             |         |            +--------------------------------- 狀態
                    |             |         +---------------------------------------------- 名稱
                    |             +-------------------------------------------------------- 型別
                    +---------------------------------------------------------------------- 指標

執行緒指標指的是JVM內部的執行緒結構，一般只在實時偵錯JVM或core檔案時才會有用。執行緒型別包括以下幾種：

  • JavaThread
  • VMThread
  • CompilerThread
  • GCTaskThread
  • WatcherThread
  • ConcurrentMarkSweepThread

部分程序可能包含daemon標識，表示該程序為守護行程，該項不一定會存在。
接下來的執行緒狀態中常見的有以下幾種：

Thread State Description
_thread_uninitialized 執行緒未建立，僅在記憶體崩潰時出現。
_thread_new 執行緒已被建立，但是沒有啟動。
_thread_in_native 執行緒正在執行原生程式碼，可能因為原生程式碼的BUG導致此問題。
_thread_in_vm 執行緒正在執行虛擬機器器程式碼。
_thread_in_Java 執行緒正在執行編譯或解釋後的Java程式碼。
_thread_blocked 執行緒被阻塞。
..._trans 以上狀態如果後邊帶有_trans，表示執行緒正在切換狀態。

訊號資訊

siginfo:si_signo=SIGSEGV: si_errno=0, si_code=0 (SEGV0), si_addr=0x0000000000000000

訊號資訊描述了導致JVM終止的異常訊號資訊，此部分資訊根據作業系統不同會有所區別，上邊的例子是linux伺服器下生成的內容，在windows下內容如下：

siginfo: ExceptionCode=0xc0000005, reading address 0xd8ffecf1
                  |                          |
                  |                          +--------- 執行緒異常時讀取的地址
                  +------------------------------------ 異常碼

計數器資訊

Registers: 
RAX=0x00007f80e2109e00, RBX=0x00007f80dc8ce000, RCX=0x0000000000001a70, RDX=0x00007f80e14c87f0
RSP=0x00007f807dca4710, RBP=0x00007f807dca4780, RSI=0x00007f807dcb47f8, RDI=0x00007f80dc8ce1e8
R8 =0x00007f807dca47a0, R9 =0x000000000000005a, R10=0x0000000000000000, R11=0x0000000000000000
R12=0x00007f807dcb47f8, R13=0x0000000000001a70, R14=0x0000000000000000, R15=0x00007f80e14c8800
RIP=0x00007f80e0cd095c, EFLAGS=0x0000000000010206, CSGSFS=0xffff000000000033, ERR=0x0000000000000007
  TRAPNO=0x000000000000000e

此部分內容為程式崩潰時程式計數器中的內容，這一部分的列印格式和伺服器的處理器型別有關，以上為我手中檔案的內容，這一部分內容與下一部分結合來看會比較有用（實際上也沒看懂）。

機器指令

Top of Stack: (sp=0x00007f807dca4710)
0x00007f807dca4710:   0000000000007ffe 00007f807dca47a0
0x00007f807dca4720:   00007f807dcb5700 00007f807dcb5680
......
0x00007f807dca48f0:   2020202020202020 2020202020202020
0x00007f807dca4900:   2020202020202020 1c00000020202020

Instructions: (pc=0x00007f80e0cd095c)
0x00007f80e0cd093c:   ff 0f 1f 00 48 8b 05 59 b3 7b 00 48 89 da 48 c1
0x00007f80e0cd094c:   ea 04 8b 00 21 d0 48 8b 15 cf 6f 7b 00 48 03 02
0x00007f80e0cd095c:   c7 00 01 00 00 00 e9 b6 fe ff ff 66 0f 1f 84 00
0x00007f80e0cd096c:   00 00 00 00 45 85 ed 74 40 84 c9 74 77 48 8b 05

以上是博主檔案的內容，因為篇幅原因中間部分隱藏了，這一部分內容包含了系統崩潰時程式計數器棧頂的32個指令。這些資訊可以通過反編譯程式編譯出崩潰地址附近的指令。需要注意的是A32和AMD64架構的指令長度不一致，所以並不一定能夠反編譯出這部分指令。

記憶體對映資訊

Register to memory mapping:
RAX=0x00007f80e2109e00 is an unknown value
RBX=0x00007f80dc8ce000 is a thread
RCX=0x0000000000001a70 is an unknown value
RDX=0x00007f80e14c87f0: <offset 0xe4b7f0> in /usr/java/jdk1.7.0_80/jre/lib/amd64/server/libjvm.so at 0x00007f80e067d000
RSP=0x00007f807dca4710 is pointing into the stack for thread: 0x00007f80dc8ce000
RBP=0x00007f807dca4780 is pointing into the stack for thread: 0x00007f80dc8ce000
RSI=0x00007f807dcb47f8 is pointing into the stack for thread: 0x00007f80dc8ce000
RDI=0x00007f80dc8ce1e8 is an unknown value
R8 =0x00007f807dca47a0 is pointing into the stack for thread: 0x00007f80dc8ce000
R9 =0x000000000000005a is an unknown value
R10=0x0000000000000000 is an unknown value
R11=0x0000000000000000 is an unknown value
R12=0x00007f807dcb47f8 is pointing into the stack for thread: 0x00007f80dc8ce000
R13=0x0000000000001a70 is an unknown value
R14=0x0000000000000000 is an unknown value
R15=0x00007f80e14c8800: <offset 0xe4b800> in /usr/java/jdk1.7.0_80/jre/lib/amd64/server/libjvm.so at 0x00007f80e067d000

此部分資訊在博主的檔案中存在，但在JDK 7和8兩個版本的檔案中並沒有相關說明。但根據RAX、RBX等內容推測是崩潰時CPU各個暫存器中所儲存的內容。

執行緒堆疊

此部分包含執行緒棧底及棧頂的地址、當前棧指標和未使用的堆疊空間。之後是堆疊幀，最多列印100幀。對於C/C++架構，可能庫名也會被列印。

當出現某些致命錯誤資訊時，可能堆疊已經損壞，在這種情況下，這部分資訊不可用。

Stack: [0x00007f807dbb5000,0x00007f807dcb6000],  sp=0x00007f807dca4710,  free space=957k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x65395c]  jni_SetByteArrayRegion+0x19c

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
J 1342  java.net.SocketInputStream.socketRead0(Ljava/io/FileDescriptor;[BIII)I (0 bytes) @ 0x00007f80d8bdc0c7 [0x00007f80d8bdc060+0x67]
J 1341 C2 java.net.SocketInputStream.read([BIII)I (567 bytes) @ 0x00007f80d8bfcc90 [0x00007f80d8bfcb00+0x190]
J 1258 C2 com.*.*.*.remote.internal.RemoteTCPConnection.receive([BII)I (775 bytes) @ 0x00007f80d8b87fc0 [0x00007f80d8b87f20+0xa0]
J 1346 C2 com.*.*.*.remote.internal.RemoteRcvThread.receiveBuffer()I (400 bytes) @ 0x00007f80d8c05630 [0x00007f80d8c05580+0xb0]
J 1032 C2 com.*.*.*.remote.internal.RemoteRcvThread.receiveOneTSH()Lcom/*/*/*/remote/internal/system/RfpTSH; (338 bytes) @ 0x00007f80d89dc354 [0x00007f80d89dc120+0x234]
J 1363% C2 com.*.*.*.remote.internal.RemoteRcvThread.run()V (2498 bytes) @ 0x00007f80d8c119b8 [0x00007f80d8c11760+0x258]
j  java.lang.Thread.run()V+11
v  ~StubRoutines::call_stub

以上紀錄檔內容包含兩個執行緒堆疊：

  • 第一部分堆疊是Native frames，列印了本地執行緒所有的方法呼叫。然而內聯方法作為上級堆疊的一部分，執行緒堆疊不會考慮執行時編譯器內聯的Java方法。本地幀的執行緒堆疊資訊提供關於崩潰的重要資訊。通過自上而下分析列表中的庫，一般可以確定引起問題的庫並報告給對應的組織。
  • 第二部分堆疊是跳過本地幀列印了內聯方法的Java幀，根據崩潰情況可能不會列印本地幀，但大概率會列印Java幀。

其他資訊

如果錯誤發生在VM執行緒或編譯器執行緒，後邊的例子中會顯示更多資訊。例如，問題出現在VM執行緒中，崩潰時VM執行緒正在執行的操作將會被列印下來。下面的例子展示了編譯器執行緒引起崩潰，執行的內容是編譯器正在編譯方法hs101t004Thread.ackermann。因為出現的問題不一致，這部分內容並沒有出現在博主的檔案中。對於HotSpot虛擬機器器來說這部分檔案可能稍微的有點不同，但都會包含完整的類名和方法名。

Current CompileTask:
HotSpot Client Compiler:754   b  
nsk.jvmti.scenarios.hotswap.HS101.hs101t004Thread.ackermann(IJ)J (42 bytes)

程序描述

程序相關內容線上程之後列印，主要包含整個程序的執行緒列表和記憶體使用情況。

執行緒列表

Java Threads: ( => current thread )
  0x00007f80dc75b000 JavaThread "Thread-12" [_thread_blocked, id=93, stack(0x00007f807d8b2000,0x00007f807d9b3000)]
  0x00007f80dc75a000 JavaThread "Thread-11" [_thread_blocked, id=92, stack(0x00007f807d9b3000,0x00007f807dab4000)]
  0x00007f80dc759800 JavaThread "Thread-10" [_thread_blocked, id=91, stack(0x00007f807dab4000,0x00007f807dbb5000)]
=>0x00007f80dc8ce000 JavaThread "RcvThread: com.*.*.*.remote.internal.RemoteTCPConnection[qmid=*,fap=10,peer=/*,localport=*,ssl=no]" daemon [_thread_in_native_trans, id=90, stack(0x00007f807dbb5000,0x00007f807dcb6000)]
  0x00007f80dc636800 JavaThread "WebSphere MQ Trace Monitor" daemon [_thread_blocked, id=89, stack(0x00007f807dcb6000,0x00007f807ddb7000)]
  ......
Other Threads:                                                                                                                                                                                                                                  
  0x00007f80dc093800 VMThread [stack: 0x00007f807f5f6000,0x00007f807f6f7000] [id=73]
  0x00007f80dc0d5000 WatcherThread [stack: 0x00007f807eeef000,0x00007f807eff0000] [id=80]

以上內容為博主手中紀錄檔檔案的內容，因為篇幅問題部分內容被省略。此部分執行緒列表中主要是VM已知的執行緒，包括Java執行緒和VM內部的執行緒。Other Threads部分主要包含使用者程式建立但沒有包含在VM內部的本地執行緒。

關於執行緒的描述與本文之前介紹的執行緒部分一致。

虛擬機器器狀態

VM state:synchronizing (normal execution)

接下來的虛擬機器器狀態主要描述了虛擬機器器當前的執行狀態，包含以下幾種：

虛擬機器器狀態 描述
not at a safepoint 正常執行
at safepoint 虛擬機器器中所有執行緒均被阻塞，等待特殊的虛擬機器器操作完成
synchronizing 一個特殊的虛擬機器器操作，需要等待虛擬機器器中所有的執行緒處於阻塞狀態

互斥鎖/管程

VM Mutex/Monitor currently owned by a thread:  ([mutex/lock_event])
[0x00007f80dc006060] Safepoint_lock - owner thread: 0x00007f80dc093800
[0x00007f80dc0060e0] Threads_lock - owner thread: 0x00007f80dc093800
[0x00007f80dc0065e0] Heap_lock - owner thread: 0x00007f80dc5a7800

此部分描述了當前執行緒持有的互斥鎖和管程。如上例所示，這些是虛擬機器器內部的互斥鎖，不是Java物件關聯的管程。它展示了程式崩潰發生時虛擬機器器持有鎖的情況，包含了鎖名稱、持有者和虛擬機器器內部互斥鎖的地址。通常情況下此部分只對非常熟悉HotSpot虛擬機器器的人有用。持有執行緒可以線上程列表中找到。

堆概覽

Heap
 PSYoungGen      total 1397248K, used 1396672K [0x0000000755500000, 0x00000007aaa80000, 0x0000000800000000)
  eden space 1396224K, 100% used [0x0000000755500000,0x00000007aa880000,0x00000007aa880000)
  from space 1024K, 43% used [0x00000007aa880000,0x00000007aa8f0000,0x00000007aa980000)
  to   space 1024K, 0% used [0x00000007aa980000,0x00000007aa980000,0x00000007aaa80000)
 ParOldGen       total 2796544K, used 14720K [0x0000000600000000, 0x00000006aab00000, 0x0000000755500000)
  object space 2796544K, 0% used [0x0000000600000000,0x0000000600e60318,0x00000006aab00000)
 PSPermGen       total 21504K, used 18411K [0x00000005fae00000, 0x00000005fc300000, 0x0000000600000000)
  object space 21504K, 85% used [0x00000005fae00000,0x00000005fbffada0,0x00000005fc300000)

此部分內容主要為堆記憶體概覽，輸出內容取決於使用的垃圾回收器，以上內容使用的是JDK 7預設的組合（Parallel Scavenge+Parallel Old）。以上內容中比較奇怪的一點是，我們的專案執行了有一段時間了，結果老年代空間使用率約等於0%，此部分需要排查程式碼，另外一點是新生代的使用率達到100%，說明崩潰時可能是在對新生代進行GC。

卡表和原生程式碼快取

Card table byte_map: [0x00007f80d7772000,0x00007f80d879c000] byte_map_base: 0x00007f80d479b000

Code Cache  [0x00007f80d879c000, 0x00007f80d8f4c000, 0x00007f80db79c000)
 total_blobs=2892 nmethods=2508 adapters=338 free_code_cache=41446Kb largest_free_block=42334144

此部分內容在官方檔案中沒有進行介紹，通過檢視其他資料得知，卡表是JVM維護的一種資料結構，用於記錄更改物件時的參照，以便提高GC效率，原生程式碼快取主要用於編譯和儲存原生程式碼。

此部分具體的用處存疑，希望有了解的大佬可以賜教。

編譯事件

Compilation events (10 events):
Event: 83314.233 Thread 0x00007f80dc0c8000 nmethod 2661 0x00007f80d8f2f590 code [0x00007f80d8f2f800, 0x00007f80d8f2fd98]
Event: 83314.235 Thread 0x00007f80dc0c8000 2662   !         bsh.Parser::AndExpression (232 bytes)
Event: 83314.235 Thread 0x00007f80dc0c5000 nmethod 2660 0x00007f80d8f363d0 code [0x00007f80d8f366e0, 0x00007f80d8f36f68]
Event: 83314.246 Thread 0x00007f80dc0c8000 nmethod 2662 0x00007f80d8f2eb50 code [0x00007f80d8f2ed40, 0x00007f80d8f2f0a0]
Event: 83499.918 Thread 0x00007f80dc0c5000 2663             java.math.BigDecimal$StringBuilderHelper::putIntCompact (197 bytes)
Event: 83499.930 Thread 0x00007f80dc0c5000 nmethod 2663 0x00007f80d8f2c750 code [0x00007f80d8f2c8c0, 0x00007f80d8f2cf98]
Event: 84638.783 Thread 0x00007f80dc0c8000 2664             java.util.AbstractList::hashCode (46 bytes)
Event: 84638.841 Thread 0x00007f80dc0c8000 nmethod 2664 0x00007f80d8f39f90 code [0x00007f80d8f3a100, 0x00007f80d8f3a378]
Event: 85085.178 Thread 0x00007f80dc0c5000 2665             sun.nio.ch.EPollSelectorImpl::updateSelectedKeys (150 bytes)
Event: 85085.233 Thread 0x00007f80dc0c5000 nmethod 2665 0x00007f80d8f38590 code [0x00007f80d8f387c0, 0x00007f80d8f39248]

此部分內容在官方檔案中未進行介紹，不過根據內容來看，此部分包含了程式崩潰前執行的十次編譯任務。

GC事件

GC Heap History (10 events):
Event: 84610.584 GC heap before
{Heap before GC invocations=309 (full 0):
 PSYoungGen      total 1397248K, used 1396764K [0x0000000755500000, 0x00000007aaa80000, 0x0000000800000000)
  eden space 1396224K, 100% used [0x0000000755500000,0x00000007aa880000,0x00000007aa880000)
  from space 1024K, 52% used [0x00000007aa980000,0x00000007aaa071b8,0x00000007aaa80000)
  to   space 1024K, 0% used [0x00000007aa880000,0x00000007aa880000,0x00000007aa980000)
 ParOldGen       total 2796544K, used 14686K [0x0000000600000000, 0x00000006aab00000, 0x0000000755500000)
  object space 2796544K, 0% used [0x0000000600000000,0x0000000600e57bd8,0x00000006aab00000)
 PSPermGen       total 21504K, used 18408K [0x00000005fae00000, 0x00000005fc300000, 0x0000000600000000)
  object space 21504K, 85% used [0x00000005fae00000,0x00000005fbffa340,0x00000005fc300000)
Event: 84610.588 GC heap after
Heap after GC invocations=309 (full 0):
 PSYoungGen      total 1397248K, used 320K [0x0000000755500000, 0x00000007aaa80000, 0x0000000800000000)
  eden space 1396224K, 0% used [0x0000000755500000,0x0000000755500000,0x00000007aa880000)
  from space 1024K, 31% used [0x00000007aa880000,0x00000007aa8d0000,0x00000007aa980000)
  to   space 1024K, 0% used [0x00000007aa980000,0x00000007aa980000,0x00000007aaa80000)
 ParOldGen       total 2796544K, used 14686K [0x0000000600000000, 0x00000006aab00000, 0x0000000755500000)
  object space 2796544K, 0% used [0x0000000600000000,0x0000000600e57bd8,0x00000006aab00000)
 PSPermGen       total 21504K, used 18408K [0x00000005fae00000, 0x00000005fc300000, 0x0000000600000000)
  object space 21504K, 85% used [0x00000005fae00000,0x00000005fbffa340,0x00000005fc300000)
}
......

此部分內容同樣在官方檔案中沒有說明，但是瞭解JVM垃圾回收的應該都可以看懂，因為篇幅問題只展示前兩段。以下對內容進行簡要說明：

Event: 84610.584 GC heap before
           |
           +------垃圾回收發生的時間，單位秒，從JVM啟動開始計時

Heap before GC invocations=309 (full 0):
                            |        |
                            |        +------此前Full GC發生的次數
                            +---------------當前GC次數（此處代表第309次GC）

其他部分表示JVM記憶體各個分割區在GC前後的使用情況，如果出現GC後相較於GC前記憶體使用量未下降的情況，則表示可能出現記憶體溢位。

逆向優化事件

Deoptimization events (10 events):
Event: 62518.966 Thread 0x00007f80dc5a7800 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8f1cea4 method=bsh.NameSpace.getClass(Ljava/lang/String;)Ljava/lang/Class; @ 16
Event: 65561.299 Thread 0x00007f801400c000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8d46158 method=sun.nio.ch.Util$BufferCache.get(I)Ljava/nio/ByteBuffer; @ 26
Event: 67079.495 Thread 0x00007f801400c000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8cad61c method=sun.nio.ch.Util$BufferCache.get(I)Ljava/nio/ByteBuffer; @ 26
Event: 67175.303 Thread 0x00007f80dc8ce000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8e80c44 method=com.*.*.*.remote.internal.system.RemoteProxyQueue.addMessage(Lcom/*/*/*/remote/internal/system/RemoteTls;Lcom/*/*/*/remote/internal/system/RfpTSH;Lcom/*/
Event: 67175.364 Thread 0x00007f801400c000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8c7c650 method=sun.nio.ch.Util$BufferCache.get(I)Ljava/nio/ByteBuffer; @ 26
Event: 70454.736 Thread 0x00007f80dc5b7000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8b23004 method=java.lang.Long.getChars(JI[C)V @ 24
Event: 70650.379 Thread 0x00007f80dc5ad000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8e0f700 method=java.util.ArrayDeque.pollFirst()Ljava/lang/Object; @ 13
Event: 76653.752 Thread 0x00007f80dc09a000 Uncommon trap: reason=bimorphic action=maybe_recompile pc=0x00007f80d8d837b4 method=java.lang.System$2.invokeFinalize(Ljava/lang/Object;)V @ 1
Event: 84618.642 Thread 0x00007f801400c000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8eef598 method=sun.nio.ch.SocketChannelImpl.translateReadyOps(IILsun/nio/ch/SelectionKeyImpl;)Z @ 140
Event: 84618.654 Thread 0x00007f801400c000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00007f80d8b00478 method=sun.nio.ch.EPollSelectorImpl.updateSelectedKeys()I @ 124

JVM會在執行過程中對程式碼進行編譯優化，過程中包含一部分不穩定的激進優化，當激進優化不成立時會通過逆向優化退回到解釋狀態進行執行，此部分就是介紹的崩潰前的十次逆向優化內容，這部分內容在官方檔案中並沒有詳細說明。

內部錯誤

Internal exceptions (10 events):
Event: 85322.248 Thread 0x00007f80dc5ad000 Threw 0x00000007a5d71078 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.249 Thread 0x00007f80dc5ad000 Threw 0x00000007a5d986f8 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.249 Thread 0x00007f80dc5ad000 Threw 0x00000007a5d98a20 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.249 Thread 0x00007f80dc5ad000 Threw 0x00000007a5d9b088 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.738 Thread 0x00007f80dc5a8800 Threw 0x00000007a92c18f8 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.738 Thread 0x00007f80dc5a8800 Threw 0x00000007a92c1c20 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.738 Thread 0x00007f80dc5a8800 Threw 0x00000007a92c4288 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.741 Thread 0x00007f80dc5b7000 Threw 0x00000007a982b580 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.741 Thread 0x00007f80dc5b7000 Threw 0x00000007a982b8a8 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319
Event: 85322.742 Thread 0x00007f80dc5b7000 Threw 0x00000007a982df10 at /HUDSON/workspace/7u-2-build-linux-amd64/jdk7u80/2329/hotspot/src/share/vm/prims/jvm.cpp:1319

此部分在官方檔案中並沒有進行說明，且當前檔案中的內容可閱讀的資訊較少，在查閱相關資料過程中發現部分錯誤此處可能列印具體的異常資訊。當前檔案中可以看出在0.5s內發生了10次內部錯誤，綜合檔案其他地方的時間來看，這個時間點很接近崩潰發生的時間，且與最後一次未發生的GC時間基本相符。

事件

Events (10 events):
Event: 85322.248 loading class 0x00007f80dc52a460 done
Event: 85322.248 loading class 0x00007f80dc52a460
Event: 85322.248 loading class 0x00007f80dc52a460 done
Event: 85322.249 loading class 0x00007f80dc52a460
Event: 85322.249 loading class 0x00007f80dc52a460 done
Event: 85322.738 loading class 0x00007f80dc52a460
Event: 85322.738 loading class 0x00007f80dc52a460 done
Event: 85322.741 loading class 0x00007f80dc52a460
Event: 85322.741 loading class 0x00007f80dc52a460 done
Event: 85322.742 Executing VM operation: ParallelGCFailedAllocation

此部分在官方檔案中並沒有進行說明，此部分主要包含JVM在崩潰前的十次操作事件，以上內容可以看出最後一次事件為ParallelGCFailedAllocation，在網上沒有查到這個操作的資料，根據字面含義為執行Parallel垃圾回收器回收失敗後的再分配過程，此處的疑點是在崩潰前新生代記憶體使用率已經是100%了，可能是這個事件導致的記憶體溢位。

記憶體資訊

Dynamic libraries:
00400000-00401000 r-xp 00000000 fd:01 268667146                          /usr/java/jdk1.7.0_80/bin/java
00600000-00601000 rw-p 00000000 fd:01 268667146                          /usr/java/jdk1.7.0_80/bin/java
01097000-010b8000 rw-p 00000000 00:00 0                                  [heap]
......
7f80e210c000-7f80e210d000 r--p 0001f000 fd:01 302335055                  /usr/lib64/ld-2.17.so
7f80e210d000-7f80e210e000 rw-p 00020000 fd:01 302335055                  /usr/lib64/ld-2.17.so
7f80e210e000-7f80e210f000 rw-p 00000000 00:00 0
7fff254c6000-7fff254e7000 rw-p 00000000 00:00 0                          [stack]
7fff25514000-7fff25516000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]

此部分資訊展示了崩潰時的記憶體資訊，這個列表在比較大的應用程式中可能會比較長，博主的檔案中這一部分不算空行佔了350多行。此部分在偵錯崩潰情況時非常有用，可以描述被使用的庫及其使用的記憶體地址，以及堆、棧和保護單元的地址。

此部分內容的格式與作業系統相關，以上例子為Linux下的格式，以下是對內容的簡單介紹：

​紀錄檔內容 實際含義
00400000-00401000 記憶體區域
r-xp 許可權(r:讀取、w:寫入、x:執行、p:私有、s:共用)
00000000 檔案偏移量
fd:01 檔案所在裝置的主要和次要ID
268667146 索引編號
/usr/java/jdk1.7.0_80/bin/java 檔名 
00400000-00401000 r-xp 00000000 fd:01 268667146   /usr/java/jdk1.7.0_80/bin/java
|<------------->|  ^      ^       ^     ^        |<- -------------------------->|
        |          |      |       |     |                       |
        |          |      |       |     |                       +------------------- 檔名
        |          |      |       |     +------------------------------------------- 索引編號
        |          |      |       +------------------------------------------------- 檔案所在裝置的主要和次要ID
        |          |      +--------------------------------------------------------- 檔案偏移量
        |          +---------------------------------------------------------------- 許可權(r:讀取、w:寫入、x:執行、p:私有、s:共用)
        +--------------------------------------------------------------------------- 記憶體區域

虛擬機器器引數和環境變數

VM Arguments:
jvm_args: -Dfile.encoding=UTF8 -Dsun.jnu.encoding=UTF8 -Xms4096m -Xmx8192m
java_command: com.giantstone.commgateway.startup.Bootstrap ../../gateway-comm-lib/lib ../config ../deploy front_core start
Launcher Type: SUN_STANDARD
                                                                                                                                                                                                                                                
Environment Variables:
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/root/bin
SHELL=/bin/bash

此部分應該是最簡單易懂的，描述的是和Java虛擬機器器有關的環境變數及其自身執行時使用的引數。

訊號處理器

Signal Handlers:
SIGSEGV: [libjvm.so+0x9a3b20], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004
SIGBUS: [libjvm.so+0x9a3b20], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004
SIGFPE: [libjvm.so+0x81e740], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004
SIGXFSZ: [libjvm.so+0x81e740], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004
SIGILL: [libjvm.so+0x81e740], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004
SIGUSR1: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGUSR2: [libjvm.so+0x81ffb0], sa_mask[0]=0x00000000, sa_flags=0x10000004
SIGHUP: SIG_IGN, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGINT: SIG_IGN, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGTERM: [libjvm.so+0x8210d0], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004
SIGQUIT: [libjvm.so+0x8210d0], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004

此部分內容為Linux特有的內容，主要描述針對訊號所使用的處理程式。

系統資訊

紀錄檔最後一大部分是作業系統相關的內容，也是整個檔案當中最直觀的部分，主要包含作業系統版本、CPU資訊和記憶體概要。

作業系統

OS:Red Hat Enterprise Linux Server release 7.0 (Maipo)
uname:Linux 3.10.0-514.el7.x86_64 #1 SMP Wed Oct 19 11:24:13 EDT 2016 x86_64
libc:glibc 2.17 NPTL 2.17
rlimit: STACK 8192k, CORE infinity, NPROC infinity, NOFILE 65536, AS infinity
load average:6.02 5.99 5.89

此部分內容為針對作業系統的基本資訊和執行中的平均負載情況。

記憶體資訊

Memory: 4k page, physical 131862044k(14543760k free), swap 33554428k(33531212k free)
 
/proc/meminfo:
MemTotal:       131862044 kB
MemFree:        14543760 kB
MemAvailable:   120724836 kB
Buffers:            1584 kB
Cached:         107254088 kB
......
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:      378736 kB
DirectMap2M:    133838848 kB

記憶體部分在檔案中實際分了兩部分，這裡我們放在一起展示，因為篇幅原因記憶體詳情只展示開頭和結尾的部分，這部分主要包含系統執行時的記憶體使用情況，這裡有個問題，我們的應用跑在容器之中，分配的容器記憶體只有8G，但這裡獲取到的記憶體則是整臺宿主機的記憶體。

CPU資訊

CPU:total 32 (1 cores per cpu, 1 threads per core) family 6 model 6 stepping 3, cmov, cx8, fxsr, mmx, sse, sse2, sse3, tsc                                                                                                                      

/proc/cpuinfo:
# 此處省略掉每個CPU核心的描述資訊

CPU資訊部分包括概覽以及對每個核心的描述，因為篇幅原因省略掉了，此處和記憶體存在同樣的問題，容器內的應用獲取到了宿主機的CPU資訊。

總結

通過查詢相關資料，對JVM致命錯誤紀錄檔內容有了初步的瞭解，在學習的過程中發現了以下幾個疑點：

  • 崩潰時正在通過JNI方式呼叫SetByteArrayRegion這個方法進行陣列處理，通過堆疊資訊可以看到是在呼叫RemoteTCPConnection.receive()時報的錯，而這個類是我們參照的MQ中的方法，後續需要對相關的程式碼進行排查，確定使用的版本是否正常，相關程式碼是否存在問題。
  • 在檢視堆記憶體和事件部分可以得知，在崩潰時記憶體中新生代的使用率已經達到了100%，在事件中也觸發了ParallelGCFailedAllocation，考慮是不是因為在呼叫RemoteTCPConnection.receive()時出現了記憶體溢位問題。
  • 容器內的應用在獲取硬體資訊時獲取到了宿主機的硬體資訊，這個地方會有一個隱患，java預設使用實體記憶體的一半來作為虛擬機器器的記憶體，如果說在使用java時沒有手動設定Xmx引數，也就意味著該程序使用的記憶體可能會遠大於容器的記憶體。此份紀錄檔檔案中可以看到設定的-Xmx=8192m，但實際我們給容器分配的記憶體也是8G，而另外的應用中使用的Tomcat並沒有設定此引數。
  • 在排查問題時還發現JDK 7本身與容器存在相容性問題，網上的資料建議使用JDK 8u131以後的版本，但是博主未在JDK 8u131的更新紀錄檔中發現相關內容，倒是在8u191的更新紀錄檔中找到了，目前計劃將JDK更新至8u201，同時使用G1垃圾回收器，驗證能不能解決之前出現的GC問題。

以上是排查過程中發現的問題，本人水平有限，可能問題定位不準確，這份總結僅供各位參考，實際的問題還需要多方面的排查和驗證。