JVM致命錯誤日誌詳解

2020 年 4 月 29 日
筆記

最近一段時間生產環境頻繁出問題，每次都會生成一個hs_err_pid*.log文件，因為工作內容的原因，之前並沒有了解過相關內容，趁此機會學習下，根據項目的使用情況，此文章針對JDK 8進行分析，不過因為素材問題，文章中引用的文件內容為JDK 7生成的文件，此處應該不影響，因為官方文檔中關於此部分說明使用的是JDK 6生成的文件。我們將按照內容在文件中出現的順序進行介紹。

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

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

JDK 7
官方文檔地址：//docs.oracle.com/javase/7/docs/
致命錯誤日誌文檔：//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:
#   //bugreport.java.com/bugreport/crash.jsp 
#

錯誤資訊記錄

前兩行主要描述了訊號類型、發起訊號的程式計數器、進程ID和執行緒ID，如下所示：

#  SIGSEGV (0xb) at pc=0x00007f80e0cd095c, pid=48, tid=140189843019520
      |      |           |                    |       |
      |      |           |                    |       +--- 執行緒ID
      |      |           |                    +----------- 進程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:
#   //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)]

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

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兩個版本的文檔中並沒有相關說明。

執行緒堆棧

此部分包含執行緒棧底及棧頂的地址、當前棧指針和未使用的堆棧空間。之後是堆棧幀，最多列印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前後記憶體使用量未下降的情況，則表示可能出現記憶體溢出。

逆向優化事件

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 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問題。

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