JVM致命错误日志详解
☆★傲天★☆ 人气:2
[toc]
最近一段时间生产环境频繁出问题，每次都会生成一个hs_err_pid*.log文件，因为工作内容的原因，之前并没有了解过相关内容，趁此机会学习下，根据项目的使用情况，此文章针对JDK 8进行分析，不过因为素材问题，文章中引用的文件内容为JDK 7生成的文件，此处应该不影响，因为官方文档中关于此部分说明使用的是JDK 6生成的文件。我们将按照内容在文件中出现的顺序进行介绍。
*PS:本人水平有限，工作中也没有太多机会进行此类知识的应用，文章内容绝大多数来自于官方文档，某些内容在官网中并没有涉及，相应的介绍不一定准确，希望各位大佬不吝赐教*
> JDK 8
> 官方文档下载地址：[https://www.oracle.com/java/technologies/javase-jdk8-doc-downloads.html](https://www.oracle.com/java/technologies/javase-jdk8-doc-downloads.html)
> 致命错误日志文档：https://img.qb5200.com/download-x/docs/technotes/guides/troubleshoot/felog.html#fatal_error_log_vm
> JDK 7
> 官方文档地址：[https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/](https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/)
> 致命错误日志文档：[https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/webnotes/tsg/TSG-VM/html/felog.html](https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/webnotes/tsg/TSG-VM/html/felog.html)
## 文件描述
错误日志是在JVM遇到致命错误时生成的日志文件，可能包括以下信息：
* 引发致命错误的异常操作或信号
* 版本和配置信息
* 引发致命错误的线程详细信息和线程堆栈记录
* 正在运行的线程及其状态的列表
* 有关堆的概要信息
* 加载的本机库的列表
* 命令行参数
* 环境变量
* 操作系统和 CPU 的详细信息
> 当问题严重到错误处理器无法收集并报告所有信息时，可能只有一部分信息会写入错误日志。
文件总共分为一下几个章节：
* 简单描述崩溃信息的文件头
* 线程描述部分
* 进程描述部分
* 系统信息部分
## 文件位置
致命错误日志文件位置可以通过 `-XX:ErrorFile`进行指定，例如：
```bash
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默认的环境变量，且默认值一样）。
## 文件头
文件头在错误日志的最开头，主要是对问题的简单描述。这部分内容同样会打印到标准输出，可能也会打印到应用程序的控制台上。示例如下：
```xml
#
# 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，如下所示：
```xml
# 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会将其编译成本地代码以提高执行效率；而被调用很少（甚至只有一次）的方法在解释模式下会继续执行，从而减少编译和优化成本。
### 崩溃原因
接下来两行描述了引发崩溃问题的函数帧
```xml
# 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方法。
### 错误信息
接下来的错误信息部分根据不同错误显示不一样的内容，在官方给的资料中提供了一份关于内部错误的错误信息，示例如下：
```xml
# 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工程师有用。
因为我们生产环境上出现的问题和示例中的问题种类不一样，所以我们拿到了这样一段信息：
```xml
# 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`标识进程为守护进程，该项不一定会存在。
接下来的线程状态中常见的有以下几种：
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:
加载全部内容