记一次 JVM 崩溃问题排查（G1 日志分析）

背景

上周五业务高峰期，有一个 java 实例毫无征兆的 crash 了，第一时间应用重启之后，将对应的崩溃日志保留，后面做分析。

先说一下该服务的具体情况：
jdk 版本：1.8.0_152-b16
服务器信息：16C32G
启动参数：-Xms18g -Xmx18g -Xss256k -XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=512m -XX:MaxDirectMemorySize=6g -XX:+DisableExplicitGC -XX:+UseG1GC -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=1024k -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./oom_info.dump -Xloggc:./oom_gcinfo.log -XX:CompressedClassSpaceSize=128m -XX:NativeMemoryTracking=detail

通过启动参数可以看到，使用的是 G1 收集器，且开启了 GC 日志打印。

排查过程

问题分析

由于 jvm 退出时，生成了 hs_err_pidxxx.log 文件，所以直接从该文件分析入手。
打开文件后，主要关注几块信息：

• 文件第一行
  这部分会简要的说明崩溃原因
• Problematic frame
  崩溃发生的帧所在
• Current thread
  崩溃发生时的线程
• siginfo
  崩溃信号信息
• Stack
  崩溃时的栈详细信息
• Native frames
  崩溃时的本地栈帧

在我的场景里，具体的信息为：

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007efc3752faec, pid=19182, tid=0x00007efbc9279700
#
# JRE version: Java(TM) SE Runtime Environment (8.0_152-b16) (build 1.8.0_152-b16)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.152-b16 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C  [libc.so.6+0x85aec]  cfree+0x1c
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#

---------------  T H R E A D  ---------------

Current thread (0x00007efc30077000):  ConcurrentGCThread [stack: 0x00007efbc917a000,0x00007efbc927a000] [id=19213]

siginfo: si_signo: 11 (SIGSEGV), si_code: 1 (SEGV_MAPERR), si_addr: 0x00007efc37ed0ff8

... 省略很多其他信息 ...

Stack: [0x00007efbc917a000,0x00007efbc927a000],  sp=0x00007efbc92788f8,  free space=1018k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  [libc.so.6+0x85aec]  cfree+0x1c

在这份报告当中，第一行直接说明了崩溃原因：
SIGSEGV (0xb) at pc=0x00007efc3752faec, pid=19182, tid=0x00007efbc9279700

SIGSEGV (0xb) 表示段错误，通常是由于尝试访问未分配或未映射的内存地址引起的。

而对应的Problematic frame: C [libc.so.6+0x85aec] cfree+0x1c也说明了这个崩溃是在执行 cfree 时发生的。
到这一步应该有了大概的概念了：jvm 运行时释放了一段未分配或者未映射的内存地址引起的。

但是怎么引起的呢？这个时候就需要通过崩溃发生时的线程Current thread来确认了，对应的值是：

ConcurrentGCThread

所以到这里，基本上就可以确认，是 G1 收集器的 bug。

问题原因

在官网看了 jdk8 的 release note 之后，找到一个 bug修复记录 JDK-8191393 : Random crashes during cfree+0x1c，里面记载了这个 bug 的修复时间和版本，bug 修复讨论 记录了 bug 产生的原因。
大概原因就是 ConcurrentMarkThread 和 VMThread 之间的竞争条件导致的。具体问题是 ConcurrentMarkThread 未完全参与 SuspendibleThreadSet 同步，导致它在某些情况下与 VMThread 不同步地执行操作。这种竞争条件可能会导致在 GC 日志 rotation 过程中发生段错误 (SIGSEGV)，尤其是在 VMThread 执行日志 rotation 的同时，ConcurrentMarkThread 也在尝试写入日志。
有兴趣的同学可以详细看看源码。