JVM致命错误日志(hs_err_pid.log)分析
概览
当jvm出现致命错误时，会生成一个错误文件 hs_err_pid
- 当出现crash时，该文件默认会生成到工作目录下，然而可以通过jvm参数指定生成路径（JDK6中引入）：-XX:ErrorFile=./hs_err_pid
.log - 该文件包含如下几类关键信息：
- 日志头文件
- 导致crash的线程信息
- 所有线程信息
- 安全点和锁信息
- 堆信息
- 本地代码缓存
- 编译事件
- gc相关记录
- jvm内存映射
- jvm启动参数
- 服务器信息
日志头信息
日志头文件包含概要信息，简述了导致crash的原因。而导致crash的原因很多，常见的原因有jvm自身的bug，应用程序错误，jvm参数配置不当，服务器资源不足，jni调用错误等。
示例：
# There is insufficient（不足） memory for the Java Runtime Environment to continue.
# Native memory allocation (mmap) failed to map 398 458 880 bytes for committing reserved（保留，预留） memory.
# Possible reasons:
# The system is out of physical RAM or swap space
# In 32 bit mode, the process size limit was hit
# Possible solutions:
# Reduce memory load on the system
# Increase physical memory or swap space
# Check if swap backing store is full
# Use 64 bit Java on a 64 bit OS
# Decrease Java heap size (-Xmx/-Xms)
# Decrease number of Java threads
# Decrease Java thread stack sizes (-Xss)
# Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
# Out of Memory Error (os_linux.cpp:2716), pid=77665, tid=140321575270144
#
# JRE version: (8.0_11-b12) (build )
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.11-b03 mixed mode linux-amd64 compressed oops)
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
可能的问题原因：
1.内存不够
查看内存 free -h 或 cat /proc/meminfo
2.进程打开数达到上限
可以通过ulimit -a来查看当前Linux系统的一些系统参数,其中max user processes是系统允许创建的最大进程数，open files是一个进程可打开的最大文件数。
# ulimit -a 命令（列出所有当前资源极限）的输出信息（其他命令可参考输出信息中括号内的提示）:
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited # 一个进程的数据段的最大值
scheduling priority (-e) 0
file size (blocks, -f) unlimited # Shell创建文件的最大体积, 1block = 512bytes
pending signals (-i) 1031426 # 最多允许多少个待处理的信号
max locked memory (kbytes, -l) 64 # 每个进程可以锁住的物理内存的最大值
max memory size (kbytes, -m) unlimited # 每个进程可以使用的常驻内存的最大值
open files (-n) 65535 # 每个进程可以同时打开的最大文件数, 不能是unlimited
pipe size (512 bytes, -p) 8 # 管道的最大值, 1block = 512bytes
POSIX message queues (bytes, -q) 819200 # POSIX的消息队列的最大值
real-time priority (-r) 0
stack size (kbytes, -s) 10240 # 单个进程能够使用的最大栈大小
cpu time (seconds, -t) unlimited # 单个进程的最大CPU时间, 也就是可使用CPU的秒数, 到硬极限时, 这个进程就会立即自杀; 到软极限时, 每秒发送一次限制超时信号SIGXCPU
max user processes (-u) 131072 #单个用户可同时运行的最大进程数, 不能是unlimited
virtual memory (kbytes, -v) unlimited # 每个进程可使用的最大虚拟内存
file locks (-x) unlimited # 每个进程能锁住的最大文件个数
对max user processes的配置, Linux系统默认先读取/etc/security/limits.conf 中的信息, 如果/etc/security/limits.d/目录下还有配置文件的话, 也会依次遍历读取, 最终, /etc/security/limits.d/中的配置会覆盖/etc/security/limits.conf 中的配置
修改/etc/security/limits.conf文件, 在文件最后添加下述内容
# nproc 用户进程数的默认限制
* soft nproc 131072
* hard nproc 131072
另外，Linux 系统默认的max open files = 1024, 在大内存服务器中, 如果运行负载比较大的程序, 很容易发生error: too many open files, 特别是提供大量静态文件访问的Web服务器、缓存服务器中这种错误更加常见.
在/etc/security/limits.conf最后增加如下两行记录
# nofile - 可以打开的最大文件数, *通配符表示对所有用户有效
* soft nofile 65535
* hard nofile 65535
注意：max open files和max user processes是不能配置unlimited的 —— 极不安全的设置, 此时系统会使用默认的配置值。
导致crash的线程信息
--------------- T H R E A D ---------------
Current thread (0x00007f9f20009000): JavaThread "Unknown thread" [_thread_in_vm, id=77666, stack(0x00007f9f29960000,0x00007f9f29a60000)]
Stack: [0x00007f9f29960000,0x00007f9f29a60000], sp=0x00007f9f29a5e330, free space=1016k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V [libjvm.so+0xa2f59a] VMError::report_and_die()+0x2ca
V [libjvm.so+0x4b2e4b] report_vm_out_of_memory(char const*, int, unsigned long, VMErrorType, char const*)+0x8b
V [libjvm.so+0x89e3b3] os::Linux::commit_memory_impl(char*, unsigned long, bool)+0x103
V [libjvm.so+0x89e909] os::pd_commit_memory(char*, unsigned long, unsigned long, bool)+0x29
V [libjvm.so+0x8985ba] os::commit_memory(char*, unsigned long, unsigned long, bool)+0x2a
V [libjvm.so+0x9091c3] PSVirtualSpace::expand_by(unsigned long)+0x53
V [libjvm.so+0x8b683e] ParMarkBitMap::initialize(MemRegion)+0x13e
V [libjvm.so+0x8ff1c9] PSParallelCompact::initialize()+0x149
V [libjvm.so+0x8bf6fd] ParallelScavengeHeap::initialize()+0x35d
V [libjvm.so+0x9fd733] Universe::initialize_heap()+0xe3
V [libjvm.so+0x9fdb74] universe_init()+0x64
V [libjvm.so+0x5d46d5] init_globals()+0x65
V [libjvm.so+0x9e445d] Threads::create_vm(JavaVMInitArgs*, bool*)+0x24d
V [libjvm.so+0x665b04] JNI_CreateJavaVM+0x74
C [libjli.so+0x703e] JavaMain+0x9e
1.以上表示导致出错的线程是0x00007f9f20009000（指针），线程类型是JavaThread，JavaThread表示执行的是java线程，关于该线程其它类型还可能是：
- VMThread：jvm的内部线程
- CompilerThread：用来调用JITing，实时编译装卸class 。 通常，jvm会启动多个线程来处理这部分工作，线程名称后面的数字也会累加，例如：CompilerThread1
- GCTaskThread：执行gc的线程
- WatcherThread：jvm周期性任务调度的线程，是一个单例对象。 该线程在JVM内使用得比较频繁，比如：定期的内存监控、JVM运行状况监控，还有我们经常需要去执行一些jstat 这类命令查看gc的情况
- ConcurrentMarkSweepThread：jvm在进行CMS GC的时候，会创建一个该线程去进行GC，该线程被创建的同时会创建一个SurrogateLockerThread（简称SLT）线程并且启动它，SLT启动之后，处于等待阶段。CMST开始GC时，会发一个消息给SLT让它去获取Java层Reference对象的全局锁：Lock
2.后面的"Unknown thread"位置显示线程名，如果后面有“daemon”表示该线程为守护线程，再后面的“[_thread_in_vm”表示线程正在执行虚拟机代码，关于该描述其它类型还可能是：
- _thread_in_native：线程当前状态
- thread_uninitialized：线程还没有创建，它只在内存原因崩溃的时候才出现
- _thread_new：线程已经被创建，但是还没有启动
- thread_in_native：线程正在执行本地代码，一般这种情况很可能是本地代码有问题
- _ thread_in_vm：线程正在执行虚拟机代码
- _ thread_in_Java：线程正在执行解释或者编译后的Java代码
- thread_blocked：线程处于阻塞状态
- …_trans：以_trans结尾，线程正处于要切换到其它状态的中间状态
最后的“id=77666”表线程ID，stack(0x00007f9f29960000,0x00007f9f29a60000)表示栈区间。
详细信息显示commit_memory错误，即无法申请内存。一般是因为 Xmx 设置过大，超过系统可用内存，JVM 申请内存失败。
进程信息
--------------- P R O C E S S ---------------
Java Threads: ( => current thread )
#所有线程信息
Other Threads:
=>0x00007f9f20009000 (exited) JavaThread "Unknown thread" [_thread_in_vm, id=77666, stack(0x00007f9f29960000,0x00007f9f29a60000)]
#安全点和锁信息
VM state:not at safepoint (not fully initialized)
VM Mutex/Monitor currently owned by a thread: None
GC Heap History (0 events):
No events
Deoptimization events (0 events):
No events
Internal exceptions (0 events):
No events
Events (0 events):
No events
- 安全点和锁信息
- 安全线信息为正常运行，其它可能得描述还有：
- not at a safepoint：正常运行状态
- at safepoint：所有线程都因为虚拟机等待状态而阻塞，等待一个虚拟机操作完成
- synchronizing：一个特殊的虚拟机操作，要求虚拟机内的其它线程保持等待状态
- 锁信息为未被线程持有，Mutex是虚拟机内部的锁，而Monitor则是synchronized锁或者其它关联到的Java对象。
- 安全线信息为正常运行，其它可能得描述还有：
jvm内存映射
Dynamic libraries:
00400000-00401000 r-xp 00000000 fd:00 1209105 /usr/local/java/jdk1.8.0_11/bin/jstack
00600000-00601000 rw-p 00000000 fd:00 1209105 /usr/local/java/jdk1.8.0_11/bin/jstack
00962000-00983000 rw-p 00000000 00:00 0 [heap]
4c8000000-4c8680000 rw-p 00000000 00:00 0
4c8680000-6c2b00000 ---p 00000000 00:00 0
6c2b00000-6c2c80000 rw-p 00000000 00:00 0
6c2c80000-7c0000000 ---p 00000000 00:00 0
......
这些信息是虚拟机崩溃时的虚拟内存列表区域。它可以告诉你崩溃原因时哪些类库正在被使用，位置在哪里，还有堆栈和守护页信息。以列表中第一条为例介绍下：
- 00400000-00401000：内存区域
- r-xp：权限，r/w/x/p/s分别表示读/写/执行/私有/共享
- 00000000：文件内的偏移量
- fd:00：文件位置的majorID和minorID
- 1209105：索引节点号
- /usr/local/java/jdk1.8.0_11/bin/jstack：文件位置
服务器信息
上面是内存信息，主要关注下swap信息，看看有没有使用虚拟内存；下面是cpu信息
OS:CentOS Linux release 7.6.1810 (Core)
uname:Linux 3.10.0-957.el7.x86_64 #1 SMP Thu Nov 8 23:39:32 UTC 2018 x86_64
libc:glibc 2.17 NPTL 2.17
rlimit: STACK 8192k, CORE 0k, NPROC 63373, NOFILE 4096, AS infinity
load average:1.80 1.52 1.08
/proc/meminfo:
MemTotal: 49802248 kB
MemFree: 238684 kB
MemAvailable: 159440 kB
Buffers: 0 kB
Cached: 101520 kB
SwapCached: 43900 kB
Active: 45037612 kB
Inactive: 3103068 kB
......
CPU:total 16 (1 cores per cpu, 1 threads per core) family 6 model 85 stepping 7, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, popcnt, avx, avx2, aes, clmul, erms, tsc, tscinvbit
/proc/cpuinfo:
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 85
model name : Intel(R) Xeon(R) Gold 5220 CPU @ 2.20GHz
stepping : 7
microcode : 0x5002f01
cpu MHz : 2200.000
cache size : 25344 KB
......
