JVM 生产环境问题定位与解决实战(七):实战篇——OSSClient泄漏引发的FullGC风暴
本文已收录于《JVM生产环境问题定位与解决实战》专栏,完整系列见文末目录
引言
在前六篇博客中,我们系统性地学习了 JVM 生产环境问题定位与解决的全套工具链,涵盖jps
、jmap
、jstat
、jstack
、jcmd
等基础工具的使用技巧,深入剖析了JConsole
、VisualVM
和 MAT
的高级应用场景,探索了JFR
与JMC
的性能分析能力,并解锁了Arthas
的在线诊断黑科技。为使读者能将理论知识转化为实战能力,笔者将分享三个真实的线上疑难案例:
- OSSClient 未关闭导致的内存泄漏和 CPU 飙升(本篇详解)
- 正则表达式回溯导致的 CPU 100%
- JVM 内存区域分配不合理导致的频繁 Full GC
本文将重点解析首个案例,完整展现从现象捕捉、根因定位到方案优化的全链路故障排查过程。
案例一:OSSClient泄漏引发的FullGC风暴
问题现象
某日线上系统突现异常:
- 接口响应延迟:TP99从200ms飙升至5s+,部分请求超时失败
- 资源指标异常:阿里云ECS服务器CPU持续150%+,Load值突破15
- 堆内存告急:Old Gen占用率>99%且持续高位
- GC风暴:每分钟触发3-4次Full GC,单次耗时8-10秒,但回收效率近乎为零
排查过程
1. 系统资源监控(TOP命令分析)
通过top
命令快速锁定异常进程:
top - 14:32:01 up 45 days, 2:15, 3 users, load average: 15.23, 14.87, 13.65
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
13749 app 20 0 26.8g 5.2g 34832 S 207.3 34.6 45:32.19 java
关键发现:
- Java进程(PID=13749)CPU占用率突破200%
- 物理内存消耗达5.2GB,存在内存泄漏嫌疑
2. 线程级CPU分析(TOP -H 定位高 CPU 线程)
通过top -H -p <pid>
穿透进程查看线程级资源占用:
top -H -p 13749
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
17911 app 20 0 12.9g 8.2g 2.3g R 99.6 26.3 45:67.89 java
17912 app 20 0 12.9g 8.2g 2.3g R 97.2 26.3 44:32.10 java
关键发现:
-
多个线程(如17911、17912)CPU占用率接近100%
-
将十进制PID转为十六进制(
printf "%x\n" 17911
=> 45f7)用于线程堆栈分析#转换为十六进制:printf "%x\n" 17911 # 输出:45f7printf "%x\n" 17912 # 输出:45f8
3. 线程堆栈分析(jstack定位GC线程)
运行jstack <pid>
生成线程堆栈快照,在生成的thread_dump.txt中搜索对应的十六进制线程ID,获取线程快照并定位热点线程:
jstack 13749 > thread_dump.txt
在thread_dump.txt
中搜索nid=0x45f7
,发现高CPU线程为GC线程:
Locked ownable synchronizers:
- None"VM Thread" os_prio=0 tid=0x00002b71d00ff800 nid=0x45f9 runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00002b71d0023800 nid=0x45f7 runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00002b71d0025800 nid=0x45f8 runnable "VM Periodic Task Thread" os_prio=0 tid=0x00002b71d034f800 nid=0x4870 waiting on condition
结论:
GC线程持续运行,说明JVM在进行高频率垃圾回收,但老年代空间无法释放。
4. GC行为监控(jstat动态观测)
使用jstat -gcutil
监控GC动态:
jstat -gcutil 13749 5000
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 0.00 85.58 99.99 93.67 89.78 5525 805.725 1007 9100.289 9906.014
0.00 0.00 100.00 99.99 93.67 89.78 5525 805.725 1008 9100.289 9906.014
0.00 0.00 100.00 99.99 93.67 89.78 5525 805.725 1008 9100.289 9906.014
0.00 0.00 40.57 99.99 93.66 89.78 5525 805.725 1008 9109.816 9915.541
0.00 0.00 71.48 99.99 93.66 89.78 5525 805.725 1008 9109.816 9915.541
0.00 0.00 90.87 99.99 93.66 89.78 5525 805.725 1008 9109.816 9915.541
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1009 9109.816 9915.541
0.00 0.00 30.91 99.99 93.66 89.78 5525 805.725 1009 9118.757 9924.482
0.00 0.00 55.48 99.99 93.66 89.78 5525 805.725 1009 9118.757 9924.482
0.00 0.00 76.63 99.99 93.66 89.78 5525 805.725 1009 9118.757 9924.482
0.00 0.00 97.42 99.99 93.66 89.78 5525 805.725 1009 9118.757 9924.482
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1010 9118.757 9924.482
0.00 0.00 24.04 99.99 93.66 89.78 5525 805.725 1010 9127.980 9933.705
0.00 0.00 68.32 99.99 93.66 89.78 5525 805.725 1010 9127.980 9933.705
0.00 0.00 91.50 99.99 93.66 89.78 5525 805.725 1010 9127.980 9933.705
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1011 9127.980 9933.705
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1011 9127.980 9933.705
0.00 0.00 50.42 99.99 93.66 89.78 5525 805.725 1011 9137.226 9942.951
0.00 0.00 83.94 99.99 93.66 89.78 5525 805.725 1011 9137.226 9942.951
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1012 9137.226 9942.951
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1012 9137.226 9942.951
0.00 0.00 54.98 99.99 93.66 89.78 5525 805.725 1012 9146.092 9951.817
0.00 0.00 85.01 99.99 93.66 89.78 5525 805.725 1012 9146.092 9951.817
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1013 9146.092 9951.817
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1013 9146.092 9951.817
0.00 0.00 51.21 99.99 93.66 89.78 5525 805.725 1013 9155.524 9961.249
0.00 0.00 89.83 99.99 93.66 89.78 5525 805.725 1013 9155.524 9961.249
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1014 9155.524 9961.249
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1014 9155.524 9961.249
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1014 9155.524 9961.249
0.00 0.00 100.00 99.99 93.66 89.78 5525 805.725 1014 9155.524 9961.249
0.00 0.00 88.08 99.99 93.71 89.72 5525 805.725 1014 9174.692 9980.417
0.00 0.00 100.00 99.99 93.71 89.72 5525 805.725 1015 9174.692 9980.417
0.00 0.00 100.00 99.99 93.71 89.72 5525 805.725 1015 9174.692 9980.417
0.00 0.00 57.17 99.99 93.71 89.72 5525 805.725 1015 9187.097 9992.822
0.00 0.00 100.00 99.99 93.71 89.72 5525 805.725 1016 9187.097 9992.822...(持续增长)
关键指标解读:
- O(老年代Old Gen):持续99.99%,Full GC无法回收
- YGC(年轻代GC事件发生的次数) : 共 5525 次,但最近未增加。
- YGCT(年轻代GC所花费的总时间):805.725 秒,平均每次 Minor GC 耗时约 0.146 秒。
- FGC(Full GC事件发生的次数):Full GC频率异常,持续增加,这表明 Old 区已满,垃圾回收器无法有效回收内存。
- FGCT(Full GC所花费的总时间):Full GC总耗时突破9187秒,平均每次 Full GC 耗时约 9.04 秒。
由于 Full GC 会触发 “Stop-the-World” 机制,导致应用程序暂停,对系统性能造成显著影响。结合线程堆栈分析和 GC 行为特征,可以判定请求响应延迟的根源在于频繁的 Full GC。接下来需要深入分析引发 GC 异常的具体原因,例如内存泄漏、对象生命周期管理不当或大对象分配失控等。
5. 堆内存转储(jmap生成hprof文件)
使用jmap -dump:live,format=b,file=heap.hprof <pid>
生成堆转储文件,以便分析内存占用情况。
jmap -dump:live,format=b,file=heap.hprof 13749
将heap.hprof下载到本地,利用工具进行分析。
6. 内存泄漏分析(MAT深度解析)
使用Eclipse Memory Analyzer(MAT)分析heap.hprof:
Step 1 - Leak Suspects报告
堆转储文件可能包含大量对象,MAT 的 Leak Suspects 报告能快速识别潜在的内存泄漏点,因此首先运行此报告。
报告发现大量 org.apache.http.impl.conn.PoolingHttpClientConnectionManager
实例由 com.aliyun.oss.common.comm.IdleConnectionReaper @ 0x6ce2d8388
线程加载,占用 Old
区内存。这提示我们 Full GC
可能与这些对象有关。
Step 2 - Histogram视图
Leak Suspects
报告指出了 PoolingHttpClientConnectionManager
的内存占用问题,但需要量化具体类及其内存占用比例,因此查看 Histogram
直方图。在MAT的Overview
页面,打开Histogram
直方图,按Retained Heap
(保留堆大小)倒序排序,发现以下类占用大量内存:
org.apache.http.impl.conn.PoolingHttpClientConnectionManager
com.aliyun.oss.common.comm.DefaultServiceClient
其中,DefaultServiceClient
是阿里云OSS SDK中的类,提示问题可能与OSS相关。
Step 3 - 按包分组分析
Histogram
直方图确认了具体类的内存占用,但是存在大量的基础类型(如char[]
、String
)和集合的实例,这些通常不是内存泄漏根源,因此按包分组分析,更容易发现项目自定义类。在 Histogram
视图中,选择 Group by package
,查看哪些包的类占用内存较多。结果显示,com.aliyun.oss
包下的类内存占用显著,确认问题与阿里云OSS组件相关。
Step 4 - 引用链追踪
按包分组基本确认了阿里云 OSS
相关类的内存占用,但需要明确这些对象为何未被 GC
回收,因此分析其引用关系以找到 GC Root
。查看 org.apache.http.impl.conn.PoolingHttpClientConnectionManager
的引用关系,进行 Path To GC Roots -> exclude all phantom/weak/soft etc. references
操作,得到所有强引用的引用路径。
发现 com.aliyun.oss.common.comm.IdleConnectionReaper @ 0x6ce2d8388
线程持有对这些对象的引用,与 Leak Suspects
报告一致。
Step 5- 查看线程细节
GC Root
指向 IdleConnectionReaper
线程,非项目自定义类。需要了解该线程的角色和行为以判断其为何持有这些对象,因此查看线程细节。进一步查看IdleConnectionReaper
线程的Thread Detail
。
查看 IdleConnectionReaper
的 Thread Detail
,确认这是一个守护线程,负责管理连接池。
由于 IdleConnectionReaper
是一个守护线程(is Daemon = true
),它作为 JVM 的一个独立线程运行,且通常不会随着用户线程的结束而终止。守护线程本身可以作为 GC Root
,因为 JVM 必须保持其存活以执行后台任务(如连接池清理)。这意味着由 IdleConnectionReaper
持有的对象(如 PoolingHttpClientConnectionManager
)可能无法通过常规的引用链分析直接查到其创建来源,因为这些对象的 GC Root
是守护线程的静态变量 connectionManagers
,而不是业务代码中的直接引用。这增加了定位问题代码的难度,可能需要结合其他工具(如 Arthas
)来追踪对象的创建路径.
Step 6 - 分析源码
Thread Detail
指向了 IdleConnectionReaper.java:78
,确认了是守护线程,但需要通过源码了解其如何持有 PoolingHttpClientConnectionManager
以及为何未释放,因此分析相关源码。
查看 IdleConnectionReaper.java:78
源码,发现该线程每隔 5 秒检查一次连接池,关闭过期和空闲时间超过 60 秒的连接。PoolingHttpClientConnectionManager
实例被添加到静态变量 ArrayList<HttpClientConnectionManager> connectionManagers 中
,通过 registerConnectionManager()
方法添加,通过 removeConnectionManager()
或 shutdown()
方法释放.
分析得出:程序通过 IdleConnectionReaper
的 registerConnectionManager()
方法创建了大量 PoolingHttpClientConnectionManager
对象,但未通过 removeConnectionManager()
或 shutdown()
方法释放,导致这些对象无法被 GC 回收。
Step 7- 分析引用关系
源码分析确认 IdleConnectionReaper
因未调用释放方法导致内存泄漏,但仍未定位系统中 PoolingHttpClientConnectionManager
的创建来源,因此需要查看其引用关系以追踪创建点。
在 Histogram
视图中,右键选择 incoming/outgoing references
查看 PoolingHttpClientConnectionManager
的引用关系,发现 com.aliyun.oss.common.comm.DefaultServiceClient
也与这些对象相关.
Step 8- 进一步分析 DefaultServiceClient
引用关系显示 DefaultServiceClient
与 PoolingHttpClientConnectionManager
相关,但需要通过源码确认其如何创建和管理这些对象,因此分析 DefaultServiceClient
源码。
查看 DefaultServiceClient
源码,发现其在构造时调用 IdleConnectionReaper.registerConnectionManager()
,在 shutdown()
方法中调用 IdleConnectionReaper.removeConnectionManager()
.
得出结论:项目中创建了大量 DefaultServiceClient
实例,但未调用 shutdown()
方法释放资源.
Step 9-代码溯源(Arthas热诊断)
问题定位的难点:DefaultServiceClient
分析确认了未调用 shutdown()
的问题,但仍需确定具体业务代码为何创建大量实例,尤其是在系统长期稳定后突然触发问题,因此需要进一步追踪。
至此,已基本确定问题是 OSSClient
未关闭导致的资源泄漏,但需要进一步定位具体业务代码。MAT 分析显示 PoolingHttpClientConnectionManager
和 DefaultServiceClient
的 GC root
均为 IdleConnectionReaper
的静态变量 connectionManagers
,且导出堆转储时执行了 GC, OSSClient
实例已被回收,难以直接追溯到具体代码。
MAT 分析受限于 GC Root 和堆转储时的 GC 影响,无法直接定位业务代码。那么有什么方法能定位到 PoolingHttpClientConnectionManager
是如何创建的吗?
在第五篇文章《JVM生产环境问题定位与解决实战(五):Arthas——不可错过的故障诊断利器》中介绍了stack - 输出当前方法被调用的调用路径
,很符合我们的需求。
使用 Arthas 的 stack
命令输出 PoolingHttpClientConnectionManager
构造方法的调用路径:
stack org.apache.http.impl.conn.PoolingHttpClientConnectionManage
最终定位:新增的批量处理业务逻辑在 com.controller.TestController.createOSSClient(TestController.java:423)
中创建了大量OSSClient实例,使用后未关闭,导致内存泄漏。
问题原因
综合排查结果,问题根源如下:
- 业务代码中批处理业务使用OSSClient访问阿里云OSS时,未调用shutdown()方法释放资源。
- 每个OSSClient实例关联一个PoolingHttpClientConnectionManager对象,这些对象被IdleConnectionReaper的静态变量connectionManagers持有,无法被垃圾回收。
- 大量未释放的PoolingHttpClientConnectionManager实例占满老年代,触发频繁的Full GC。
- Full GC为“Stop-the-World”事件,导致应用线程暂停,GC线程占用大量CPU,表现为CPU使用率飙升至200%及请求延迟。
优化建议
-
正确释放资源:确保在使用
OSSClient
后调用shutdown()
。推荐使用try-finally
或try-with-resources(若SDK支持AutoCloseable)
:OSS ossClient = new OSSClientBuilder().build(endpoint, accessKeyId, accessKeySecret); try {ossClient.putObject(bucketName, key, new File("file.txt")); } finally {ossClient.shutdown(); }
-
单例模式优化:如果
OSSClient
需要重复使用,可通过单例模式或连接池管理,避免频繁创建和销毁:public class OSSClientHolder {private static final OSS ossClient = new OSSClientBuilder().build(endpoint, accessKeyId, accessKeySecret);public static OSS getOSSClient() {return ossClient;}public static void shutdown() {ossClient.shutdown();} }
验证
为验证优化措施的效果,进行了以下实验:
- createOSSClient:存在问题的原始代码,未关闭 OSSClient 实例。
- createOSSClient1:优化后的代码,使用后调用 shutdown() 释放 OSSClient 实例。
- createOSSClient2:优化后的代码,采用单例模式管理单一 OSSClient 实例。
实验环境与流程
- 环境设置:
- 项目启动时启用 JVM GC 日志,配置参数为:
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseSerialGC
。 - 使用
jvisualvm
工具连接到 Java 进程进行监控。 - 使用
JMeter
进行1000次并发请求。
- 项目启动时启用 JVM GC 日志,配置参数为:
- 测试流程:
-
对三种方法(
createOSSClient
、createOSSClient1
、createOSSClient2
)分别进行 1000 次压力测试。 -
在 jvisualvm 的抽样器(Sampler)界面,设置内存监控,并使用正则表达式筛选以下对象:
(org\.apache\.http\.impl\.conn\.PoolingHttpClientConnectionManager|com\.aliyun\.oss\.OSSClient|com\.aliyun\.oss\.common\.comm\.DefaultServiceClient)
-
分析 GC 日志和 jvisualvm 快照,观察实例数量和 GC 行为。
-
测试结果
createOSSClient(问题代码)
-
行为:创建 1000 个 PoolingHttpClientConnectionManager、OSSClient 和 DefaultServiceClient 实例。
-
GC 结果:
- OSSClient 实例最终能够被垃圾回收。
- 由于 IdleConnectionReaper 的静态引用,PoolingHttpClientConnectionManager 和 DefaultServiceClient 实例无法被回收,,导致内存泄漏。
-
可视化证据:
createOSSClient1(资源清理)
- 行为:创建 1000 个实例,但在使用后调用 shutdown() 释放 OSSClient 资源。
- GC 结果:
- 经过两次 Minor GC,所有 1000 个 PoolingHttpClientConnectionManager、OSSClient 和 DefaultServiceClient 实例被完全回收。
- 第一次 GC:
- OSSClient 实例全部回收。
- PoolingHttpClientConnectionManager 和 DefaultServiceClient 部分回收。
- GC 日志:
2025-04-22T17:20:53.987-0800: 776.023: [GC (Allocation Failure) 2025-04-22T17:20:53.987-0800: 776.023: [DefNew: 148740K->17299K(157248K), 0.0224669 secs] 188299K->59312K(506816K), 0.0225411 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
- 可视化证据:
- 第二次 GC:
- 剩余的 PoolingHttpClientConnectionManager 和 DefaultServiceClient 实例全部回收。
- GC 日志:
2025-04-22T17:24:47.531-0800: 1009.572: [GC (Allocation Failure) 2025-04-22T17:24:47.531-0800: 1009.572: [DefNew: 157075K->5760K(157248K), 0.0193343 secs] 199088K->60437K(506816K), 0.0193803 secs] [Times: user=0.01 sys=0.01, real=0.02 secs]
createOSSClient2(单例模式)
-
行为:仅创建 1 个 PoolingHttpClientConnectionManager、OSSClient 和 DefaultServiceClient 实例。
-
GC 结果:
- OSSClient 实例在 Minor GC 后被回收。
- 手动触发 Full GC 后,PoolingHttpClientConnectionManager 和 DefaultServiceClient 仍保留 1 个实例(符合单例模式预期)。
2025-04-22T18:04:12.163-0800: 141.076: [GC (Allocation Failure) 2025-04-22T18:04:12.163-0800: 141.076: [DefNew: 147843K->17471K(157248K), 0.0190248 secs] 186553K->62863K(506816K), 0.0190696 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 2025-04-22T18:04:24.007-0800: 152.920: [Full GC(手动触发) (System.gc()) 2025-04-22T18:04:24.007-0800: 152.920: [Tenured: 45391K->59618K(349568K), 0.0779813 secs] 74436K->59618K(506816K), [Metaspace: 48021K->48021K(1093632K)], 0.0782380 secs] [Times: user=0.07 sys=0.00, real=0.08 secs]
-
可视化证据:
结论
实验结果验证了问题分析和优化建议的正确性:
- 不调用shutdown()会导致内存泄漏:PoolingHttpClientConnectionManager等关键组件无法回收
- 正确调用shutdown()可解决问题:所有资源都能被GC正常回收
- 单例模式是更优方案:既能避免资源泄漏,又能减少重复创建开销
建议在实际项目中:
- 对于短期使用的OSSClient,必须使用try-finally保证关闭
- 对于频繁使用的场景,推荐使用单例模式管理
- 定期监控JVM内存和GC情况,及早发现潜在问题
附录:系列目录
- JVM生产环境问题定位与解决实战(一):掌握jps、jmap、jstat、jstack、jcmd等基础工具
- JVM生产环境问题定位与解决实战(二):JConsole、VisualVM到MAT的高级应用
- JVM生产环境问题定位与解决实战(三):揭秘Java飞行记录器(JFR)的强大功能
- JVM生产环境问题定位与解决实战(四):使用JMC进行JFR性能分析指南
- JVM生产环境问题定位与解决实战(五):Arthas——不可错过的故障诊断利器
- JVM生产环境问题定位与解决实战(六):总结篇——问题定位思路与工具选择策略
- ➡️ 当前:JVM 生产环境问题定位与解决实战(七):实战篇——OSSClient泄漏引发的FullGC风暴
🔥 下篇预告:《JVM 生产环境问题定位与解决实战(八):实战篇——正则表达式回溯导致的 CPU 100%》
🚀 关注作者,获取实时更新通知!有问题欢迎在评论区交流讨论~