008-JVM堆外内存泄露排查

版本	内容	时间
V1	新建	2025-04-08 21:25:45

背景&现象

某个出海服务，需要记录设备日志，目前该记录操作会导致 JVM 频繁 Full GC，之前的开发使用动态配置开关将记录设备日志的操作给关掉了。

排查方法

1. 初步观察：确定排查方向；
2. 测试环境复现：复现问题；
3. 定位问题：分析问题根因；
4. 代码改造：测试环境验证；
5. 修复上线：观察改造效果；
6. 问题沉淀：后续如何避免；

问题排查和分析

初步观察-确定排查方向

打开记录设备日志的动态配置开关。

	监控	分析
JVM 监控		1）GC 次数明显变多，且有一次 full GC； 2）非堆内存增长的很快，怀疑有堆外内存泄漏，可能有很多类加载；
机器监控		1）开关开启后，CPU 使用率上升了 2 ~ 3 个百分点； 2）机器负载也有上升，但是这点负载对该配置影响并不大；

测试环境复现、定位问题

排查思路	猜想/验证	详情	小结论
full gc 原因	根据上面监控初步怀疑是频繁类加载导致的 metaspace 不够，触发 full gc。	从测试环境机器上下载 gc 日志，查看最近几次触发 full gc 的原因 简单展示下 full gc 的原因： 2024-09-20T15:01:21.966+0800: 861343.836: [GC (Allocation Failure) 2024-09-20T15:01:21.967+0800: 861343.836: [ParNew: 794478K->9617K(884736K), 0.0231782 secs] 1002604K->217743K(2523136K), 0.0236186 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 2024-09-20T15:06:39.123+0800: 861660.993: [Full GC (Metadata GC Threshold) 2024-09-20T15:06:39.123+0800: 861660.993: [CMS: 208125K->209470K(1638400K), 0.4697069 secs] 842719K->209470K(2523136K), [Metaspace: 213257K->213257K(1288192K)], 0.4743622 secs] [Times: user=0.48 sys=0.00, real=0.48 secs]	已确定：通过日志确定确实就是 metaspace 不够，触发 full gc 了。
类加载情况	为了查看服务的类加载情况，我在测试环境的启动参数中增加下面两个 JVM 参数，打印类加载和类卸载的情况 -XX:+TraceClassLoading -XX:+TraceClassUnloading	重启服务后，发现日志打印了很多下面类加载的日志	已确定：基本上可以确定就是类加载导致 metaspace 内存不够了。
定位代码	尝试定位具体代码	可以看到是 fastjson 导致的，先看 DeviceDataToES 相关的 json 操作，可以定位到 DeviceDataToES#buildDataToES 方法 可以定位到具体代码：SerializeConfig config = new SerializeConfig(); 继续深入： 继续看该 classLoader 使用的地方	**已确定：**已经定位到 metaspace 占用内存一直增长的具体代码了
测试环境复现	进一步验证问题代码导致 metaspace 溢出	简单压测一下触发该方法的 topic，发现下面日志疯狂打印： 对应监控 metaspace 占用内存陡增， 对应类加载也激增： 在触发一次 full gc 后，日志打印如下：说明卸载了大量多余的类 arthas 查看 ASMClassLoader 的实例个数和类加载的数量	压测确定问题代码导致 metaspace 占用内存一直增长，且 full gc 后卸载了这些类。

代码改造、修复上线

SerializeConfig 作为成员变量时，每次会使用新的类加载器去加载要序列化的类。将 SerializeConfig 抽取出来即可。

问题沉淀

• 涉及核心链路改动时，在测试环境压测，避免线上出现严重的性能 bug。
• 使用到 ASM 字节码相关技术、框架时，需要防止频繁的类加载使元空间内存不足，导致频繁的 full GC。