JVM致命错误日志详解

小程序：扫一扫查出行
【扫一扫了解最新限行尾号】
复制小程序

最近一段时间生产环境频繁出问题，每次都会生成一个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
| | +-------------------------------- 程序计数器对应的指针
| +-------------------------------------------- 信号值（十六进制）
+--------------------------------------------------- 信号名称


信号名称是操作系统自身的一种信息，CentOS 7下共有以下35种，可在/usr/include/bits/signum.h中查看其具体的声明

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文件来定位引起崩溃的指令。
+----------------- 帧类型


帧类型包括以下几种：

关于例子中描述的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)]


第一部分展示了引发致命错误的线程，以上为生产的实际信息，因为敏感信息，内容中部分字段使用*进行了脱敏。各部分说明如下：

Current thread (0x0805ac88): JavaThread "main" [_thread_in_native, id=21139, stack(0x7dbb5000, 0x7dcb6000)]
| | | | | |
| | | | | +--------- 栈区间
| | | | +---------------------- ID
| | | +--------------------------------- 状态
| | +---------------------------------------------- 名称
| +-------------------------------------------------------- 类型
+---------------------------------------------------------------------- 指针


线程指针指的是JVM内部的线程结构，一般只在实时调试JVM或core文件时才会有用。线程类型包括以下几种：

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

daemon标识进程为守护进程，该项不一定会存在。

接下来的线程状态中常见的有以下几种：

信号信息

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 1c00000020202020Instructions: (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+0x19cJava 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)


接下来的虚拟机状态主要描述了虚拟机当前的运行状态，包含以下几种：

互斥锁/管程

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: 0x00007f80d479b000Code 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_STANDARDEnvironment 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问题。

以上是排查过程中发现的问题，本人水平有限，可能问题定位不准确，这份总结仅供各位参考，实际的问题还需要多方面的排查和验证。