码农戏码

新生代农民工的自我修养

0%

通过hs_err_pid日志文件分析Java进程崩溃原因

前一段时间,Java服务端经常崩溃,每天基本需要重启两次

之前出现过内存泄漏,但这次通过grafana查看,各项指标看着也正常,内存没有大幅上升

不过在查看整个宿主机时,发现整台机器内存一直在高位运行

所以依然怀疑是内存因素

措施一:把Java应用配置上JVM参数,-Xmx,限制一下整个应用内存使用,Java部署在Docker里面,Docker没有做内存限制
默认使用的内存似乎是32G,不管在128G内存的宿主机上,还是1024G的宿主机上,都差不多是这个数字

当参加了JVM参数,-Xms25G 时,重启次数会减少,三天重启一次

说明,内存因素的确是存在的,但根本原因是什么?

在服务器上发现了一份文件:hs_err_pid781.log

日志是怎么产生的

hs_err_pid<进程号>.log 是 JVM 的默认安全机制——当 JVM 遇到无法恢复的致命错误时,会在进程崩溃前自动生成此文件,相当于 JVM 的”临终遗言”。

触发条件:

错误类型 是否生成 hs_err log 说明
SIGSEGV / SIGBUS(native 内存越界) ✅ 是 JVM 内部访问了非法内存地址
Native OOM(malloc 失败) ✅ 是 malloc 失败
JVM 内部断言失败 ✅ 是 JVM 自身逻辑检测到不一致
Java 堆 OOM(OutOfMemoryError) ❌ 否 这是可恢复的 Java 异常,应用可 catch
StackOverflowError ❌ 否 可恢复

不生成的情况: 可恢复的 Java 层异常(堆 OOM、StackOverflow)不会触发此文件,因为 JVM 还能继续运行。只有 JVM 自身内部崩溃(native 层无法继续)才会生成。

1
2
3
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32744 bytes for ChunkPool::allocate
# Out of Memory Error (arena.cpp:81), pid=1, tid=37

JVM 在执行 BulkRevokeBias(批量撤销偏向锁)操作时,需要通过 Arena 内存池分配 32KB 的原生内存,malloc 调用失败,JVM 无法继续运行,直接崩溃。

日志结构

通过分析,文本的整体结构

1
2
3
4
5
6
7
8
9
10
11
12
13
┌─────────────────────────────────────────────┐
│ 1. 头部报错信息 (~27 行, 0.02%) │ ← 崩溃类型与建议
│ 2. SUMMARY (~7 行, 0.01%) │ ← 命令行/主机/时间
│ 3. THREAD (崩溃线程) (~28 行, 0.02%) │ ← 崩溃线程调用栈
│ 4. PROCESS (线程列表) (~40050行, 36.6%) │ ← 31952个线程详情 ⚠️最大段
│ 5. VM state / Mutex (~5 行, <0.01%) │ ← safepoint状态
│ 6. Heap (堆内存详情) (~3400行, 3.1%) │ ← G1 region逐个列出
│ 7. 运行时事件记录 (~70 行, 0.06%) │ ← 各种事件最近20条
│ 8. Dynamic libraries (~65734行,59.9%) │ ← native库内存映射 ⚠️最大段
│ 9. VM Arguments (~50 行, 0.04%) │ ← JVM启动参数
│ 10. SYSTEM (~180 行, 0.16%) │ ← OS/CPU/内存信息
│ 11. vm_info (~3 行, <0.01%) │ ← JVM版本
└─────────────────────────────────────────────┘

最终可以发现

项目 结论
崩溃类型 Native OOM(malloc 失败),不是 Java 堆 OOM
直接触发 BulkRevokeBias 操作时 Arena 内存分配失败
根本原因 线程泄漏——31952个线程消耗了约31GB原生内存
加剧因素 CompressedOops Zero Based 模式限制了原生内存地址空间
堆状态 使用率仅20.6%,堆完全正常,问题不在堆
系统状态 物理内存仅剩592MB,Swap已用9GB

一句话总结:线程泄漏导致原生内存耗尽,Java堆监控看不到这个问题,最终在偏向锁撤销操作时malloc失败导致JVM崩溃。

在日志的线程列表中,的确发现了大量的线程:

1
2
3
4
5
6
7
0x00007efdc0a00000,0x00007efdc0b00000)]
0x00007effeca46000 JavaThread "pool-3068-thread-3" [_thread_blocked, id=4218, stack(0x00007efdb9400000,0x00007efdb9500000)]
0x00007effeca47800 JavaThread "pool-3068-thread-4" [_thread_blocked, id=4219, stack(0x00007efdbbc00000,0x00007efdbbd00000)]
0x00007effec024800 JavaThread "pool-3068-thread-5" [_thread_blocked, id=4220, stack(0x00007efdb8e00000,0x00007efdb8f00000)]
0x00007effec026000 JavaThread "pool-3068-thread-6" [_thread_blocked, id=4221, stack(0x00007efdc0700000,0x00007efdc0800000)]
0x00007effec027000 JavaThread "pool-3068-thread-7" [_thread_blocked, id=4222, stack(0x00007eff30800000,0x00007eff30900000)]
0x00007effec028800 JavaThread "pool-3068-thread-8" [_thread_blocked, id=4223, stack(0x00007efdb8700000,0x00007efdb8800000)]

但这些线程是哪个线程池创建的,还得去排查代码。

这其实再一次印证了使用线程池规范:

关于线程池命名,阿里巴巴Java开发手册中有一条**【强制】**规约,原文表述如下:

【强制】创建线程或线程池时请指定有意义的线程名称,方便出错时回溯。

手册将这条规约与“禁止用Executors创建线程池”放在同等重要的位置,均为强制要求。这足以说明命名规范在生产环境中的重要性。

遵循规范后,当程序出现问题(如死锁、CPU飙升)时,我们通常会使用jstack命令导出当前线程快照进行分析。一个有明确业务含义的线程名,能让开发者在成百上千条线程堆栈信息中,一眼定位到问题线程所属的业务模块,从而大大缩短故障排查时间。

这些规范都是前人的血泪史!