记一次内存泄漏导致的线上超时问题

最近新上线功能使用了线程池来优化异步处理消息，对于CPU的使用率有所升高，自从新版本上线后，发现运行每隔几天就会出现超时的问题，经过排查发现是内存泄漏频繁YGC导致的，记录下本次排查的一些思路。

问题排查过程

定位问题线程 VM Thread

出现超时问题，首先查看CPU使用率，发现CPU使用率飙升到平时的5倍多；

CPU使用率 200%+，1min 负载在6左右，由于机器是4核的，按理说CPU还有余量。

# 查看CPU使用率和负载的情况,java进程PID = 1
top

还是查看CPU使用率最高的线程，为何异常占用CPU资源

# 查看线程的CPU使用率
top -Hp 1

结果显示 PID=74 这个线程占CPU较高且持续出现，

# 将PID转为16进制，结果是 0x4a
printf "%x\n"# 由于Java程序运行在 ubuntu 下，切换用户
su ubuntu
# 保存当前线程转储文件到本地
jstack 1 > thread_dump.txt# 查询 对应线程 0x4a 的运行情况，打印出其后的30条日志
less thread_dump.txt | grep -A 30 "0x4a"

输出如下所示

"VM Thread" os_prio=0 tid=0x00007f6f244c0800 nid=0x4a runnable "Gang worker#0 (Parallel GC Threads)" os_prio=0 tid=0x00007f6f24027000 nid=0x38 runnable "Gang worker#1 (Parallel GC Threads)" os_prio=0 tid=0x00007f6f24028800 nid=0x39 runnable "G1 Main Concurrent Mark GC Thread" os_prio=0 tid=0x00007f6f24042000 nid=0x3d runnable "Gang worker#0 (G1 Parallel Marking Threads)" os_prio=0 tid=0x00007f6f24044000 nid=0x3e runnable "G1 Concurrent Refinement Thread#0" os_prio=0 tid=0x00007f6f2402e800 nid=0x3c runnable "G1 Concurrent Refinement Thread#1" os_prio=0 tid=0x00007f6f2402d000 nid=0x3b runnable "G1 Concurrent Refinement Thread#2" os_prio=0 tid=0x00007f6f2402b000 nid=0x3a runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007f6f2450c000 nid=0x63 waiting on condition JNI global references: 529

即 VM Thread 这个线程占据了较多CPU资源。什么是VM Thread 呢？

VM Thread 是 JVM 内部的一个核心线程，负责执行需要 全局安全点（Safepoint） 的操作。主要负责：

协调安全点：
1. 当 JVM 需要执行某些关键操作（如垃圾回收、代码反优化、线程栈dump）时，必须确保所有应用线程都进入安全点（即线程暂停在已知的安全位置，不会修改堆内存）。
2. VM Thread 负责 触发安全点 并等待所有应用线程到达安全点，再执行后续操作。
处理 JVM 内部操作：如偏向锁撤销、线程挂起/恢复等；

MAT分析是否存在内存泄漏

VM Thread 不是 CPU 飙升的主因，但 G1回收期的 GC 线程和 GC 行为（如频繁 Young GC、并发标记、Full GC）可能导致 CPU 高负载，因此分析堆内存使用情况。使用 jstat命令可以查看堆内存各部分的使用量

# 间隔2s输出堆内存使用情况
jstat -gc 1 2s输出列含义：
S0C, S1C: Survivor 0和1的容量（Capacity）
S0U, S1U: Survivor 0和1已使用（Used）
EC: Eden区容量
EU: Eden区已使用
OC: 老年代容量
OU: 老年代已使用
MC: Metaspace容量
MU: Metaspace已使用
CCSC: Compressed Class Space容量
CCSU: Compressed Class Space已使用
YGC: Young GC次数
YGCT: Young GC总时间
FGC: Full GC次数
FGCT: Full GC总时间
GCT: 总GC时间

部分输出如下，可以看到

OU 近似等于 OC，可能存在老年代被填满的风险，进而触发Full GC；

FGC大于0，已出现 Full GC的情况；

Young GC的情况。YGC从18476逐渐增加到18486，每次输出间隔2秒，YGC次数增加了约10次，说明Young GC发生得非常频繁，大约每2秒就有一次Young GC。YGCT的总时间是229秒左右，每次Young GC的平均时间约12毫秒每次。

在这里插入图片描述

可以看出堆内存占用异常，发生了内存泄漏的问题，导出堆栈信息进行分析，

# PID = 1 堆栈转储
jmap -dump:format=b,file=heap.hprof 1

打开MAT工具，从MAT提供的可疑报告以及统计中可以看到， KryoConnInfo这个对象内存对象极多，远远超出了合理值，自此找到了问题在哪，进一步分析代码，发现是引用的某个sdk存在消息乱序的问题没有相应进行处理，导致消息无法被清除进而导致内存泄漏。

在这里插入图片描述

修复内存泄漏问题

最后一步，分析代码，修复问题。

若有不同见解欢迎讨论~