线上线程堆积导致的oom排查思路

文章描述了一个使用seaweedfs作为文件存储服务的Java项目出现OOM问题的排查过程。通过jmap和jstack等工具,发现大量线程在等待条件,主要涉及Lettuce(Redis连接池)的线程堆积。问题可能源于grpc调用缺乏超时设置,导致线程长时间等待服务响应。

背景

一个项目文件存储服务选型seaweedfs,一个go 实现的分布式存储系统,项目使用Java作为开发语言,一个场景是客户通过http上传文件到fileService服务,fileService 收到文件之后,调用seaWeedFs-client 上传文件到seaweedfs 服务器,在运行一段时间之后发现大量的文件上传等待线程,最终导致项目oom.

排查oom

第一阶段,既然是oom 考虑的是文件读取到内存值没有正确释放,生产环境执行

ps -aux |grep "file"

定位到servicep id

获取dump文件
jmap -dump:format=b,live,file=/home/app/app.dmump 13245

获取一个近20G 的大文件,没办法只能在服务器上解析。

之后重启服务,运行几分钟之后再次获取一个2G大的文件,下载到本地

使用MAT 分析工具,分析得出
大部分是上传线程在等待占用了内存,

接下来分析线程运行情况,

首先看进程13245 下由多少个线程

命令:pstree 13245

[root@nz-travel ~]# pstree 11008
java───42*[{java}]

然后使用

jstack -l 11008

发现大量的waiting 线程

"lettuce-eventExecutorLoop-1-2" #39 daemon prio=5 os_prio=0 cpu=52.93ms elapsed=9153247.42s tid=0x00007f7c50007800 nid=0x32 waiting on condition  [0x00007f7c356e8000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park(java.base@11.0.14.1/Native Method)
	- parking to wait for  <0x00000000875bde70> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(java.base@11.0.14.1/LockSupport.java:194)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.14.1/AbstractQueuedSynchronizer.java:2081)
	at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.14.1/LinkedBlockingQueue.java:433)
	at io.netty.util.concurrent.SingleThreadEventExecutor.takeTask(SingleThreadEventExecutor.java:243)
	at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:64)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)

   Locked ownable synchronizers:
	- None

统计waiting 线程的数据

通过关键字筛选

jstack -l 11008 |grep "waiting on condition" -C10

统计数据

jstack -l 11008 |grep "waiting on condition" |wc -l

查看线程开始时间

[root@nz-travel ~]# ps -Lo tid,etime,lstart -p 11008 
    TID     ELAPSED                  STARTED
  11008 105-22:56:41 Thu Dec 22 23:41:33 2022
  11061 105-22:56:40 Thu Dec 22 23:41:34 2022
  11066 105-22:56:40 Thu Dec 22 23:41:34 2022
  11067 105-22:56:40 Thu Dec 22 23:41:34 2022
  11068 105-22:56:40 Thu Dec 22 23:41:34 2022
  11069 105-22:56:40 Thu Dec 22 23:41:34 2022
  11070 105-22:56:40 Thu Dec 22 23:41:34 2022
  11071 105-22:56:40 Thu Dec 22 23:41:34 2022
  11072 105-22:56:40 Thu Dec 22 23:41:34 2022
  11073 105-22:56:40 Thu Dec 22 23:41:34 2022
  11074 105-22:56:40 Thu Dec 22 23:41:34 2022
  11075 105-22:56:40 Thu Dec 22 23:41:34 2022
  11076 105-22:56:40 Thu Dec 22 23:41:34 2022
  11077 105-22:56:40 Thu Dec 22 23:41:34 2022
  11078 105-22:56:40 Thu Dec 22 23:41:34 2022
  11079 105-22:56:40 Thu Dec 22 23:41:34 2022
  11080 105-22:56:40 Thu Dec 22 23:41:34 2022
  11100 105-22:56:40 Thu Dec 22 23:41:34 2022
  11111 105-22:56:34 Thu Dec 22 23:41:40 2022
  11112 105-22:56:34 Thu Dec 22 23:41:40 2022
  11113 105-22:56:34 Thu Dec 22 23:41:40 2022
  11114 105-22:56:33 Thu Dec 22 23:41:41 2022
  11116 105-22:56:30 Thu Dec 22 23:41:44 2022
  11117 105-22:56:30 Thu Dec 22 23:41:44 2022
  11118 105-22:56:30 Thu Dec 22 23:41:44 2022
  11707 105-22:52:50 Thu Dec 22 23:45:24 2022
  11711 105-22:52:50 Thu Dec 22 23:45:24 2022
  11713 105-22:52:50 Thu Dec 22 23:45:24 2022
  11722 105-22:52:47 Thu Dec 22 23:45:27 2022
  11723 105-22:52:47 Thu Dec 22 23:45:27 2022
  11724 105-22:52:47 Thu Dec 22 23:45:27 2022
  11725 105-22:52:46 Thu Dec 22 23:45:28 2022
  11726 105-22:52:46 Thu Dec 22 23:45:28 2022
  11727 105-22:52:38 Thu Dec 22 23:45:36 2022
  11728 105-22:52:38 Thu Dec 22 23:45:36 2022
  11834 105-22:46:17 Thu Dec 22 23:51:57 2022
  11835 105-22:46:10 Thu Dec 22 23:52:04 2022
  11836 105-22:46:10 Thu Dec 22 23:52:04 2022
  11837 105-22:46:10 Thu Dec 22 23:52:04 2022
  11838 105-22:46:10 Thu Dec 22 23:52:04 2022
  11839 105-22:46:10 Thu Dec 22 23:52:04 2022
  11840 105-22:46:08 Thu Dec 22 23:52:06 2022
 284872    22:45:26 Thu Apr  6 23:52:48 2023

筛选某个线程

ps -Lo tid,lstart 1 | grep 26949

分析问题

以上文的命令举例:

lettuce 是关键字, 是Redis连接池的中的线程, 如果发生了线程堆积,从Redis 链接配置,链接池中间件代码分析入手解决问题,

线程等待一般是死锁或者线程等待资源,死锁是jstack 会给出提示比较容易定位问题,线程等待就需要具体代码分析等待的资源情况

线上遇到是三方包使用的grpc 调用服务端接口,但是没有超时逻辑,导致线程一直在等待服务端返回

参考资料:https://www.fancv.com/article/1680877733

<think>我们正在讨论当GC导致CPU资源飙升时,如何排查内存泄漏。 根据用户提供的引用[1]和引用[2],我们可以得知: - 引用[1]提到:如果FGC(Full GC)次数很大且一直增大,可以确认发生了Full GC。同时,可以使用`jmap -heap`查看堆内存,特别是老年代内存使用情况,当达到阈值时会触发Full GC。 - 引用[2]描述了一个场景:线上报警,CPU占用90%以上,JVM监控显示在短时间内发生了多次Young GC和一次Full GC。 因此,当GC导致CPU飙升时,我们怀疑可能是内存泄漏导致频繁GC,进而消耗大量CPU资源。排查内存泄漏的方法如下: 步骤1:确认GC情况 - 查看GC日志(根据之前的问题,我们已经知道如何查看GC日志的位置) - 使用`jstat -gcutil <pid> <interval> <count>`命令动态观察GC情况,例如: ```bash jstat -gcutil 12345 1000 10 # 每1秒输出一次,共10次 ``` 关注: - YGC(Young GC)和YGCT(Young GC时间) - FGC(Full GC)和FGCT(Full GC时间) - 各内存区域(Eden, Old, Metaspace等)的使用率 步骤2:分析内存使用 - 使用`jmap -heap <pid>`查看堆内存配置及使用情况,特别是老年代(Old Generation)的使用率是否接近100%且频繁触发Full GC。 - 使用`jmap -histo:live <pid> | head -20`查看存活对象中哪些类的实例数量最多及其占用的内存大小。如果发现某些类的实例数量异常多,则可能是泄漏点。 步骤3:生成堆转储文件(Heap Dump)进行深入分析 - 生成堆转储文件: ```bash jmap -dump:format=b,file=heap_dump.hprof <pid> ``` 注意:生成堆转储文件会暂停应用,线上环境需谨慎(建议在低峰期或故障时操作)。 - 使用分析工具(如Eclipse MAT, VisualVM, JProfiler)打开堆转储文件,分析: - 内存泄漏报告(Leak Suspects) - 查看大对象(Dominator Tree) - 分析对象的引用链,找到无法被回收的对象及其GC Root。 步骤4:结合代码定位问题 - 根据堆转储分析结果,定位到具体对象和类,再结合代码分析这些对象为何无法被回收。 常见原因: - 静态集合类持有对象引用未释放 - 资源未关闭(如数据库连接、文件流等) - 监听器未注销 - 缓存未清理 步骤5:监控与验证 - 修复后,通过压力测试或线上监控验证内存泄漏是否解决(观察老年代内存是否稳定,Full GC频率是否降低)。 注意事项: - 在CPU飙升时,可以先通过`top`命令确认是Java占用CPU高,再通过`top -Hp <pid>`查看具体线。如果发现GC线(如名字包含'GC')占CPU高,则基本确认是GC问题。 - 如果频繁Full GC但内存回收效果不明显(每次Full GC后老年代内存回收很少),则内存泄漏的可能性很大。 引用[1]中提到的方法(使用`jmap -heap`查看老年代内存使用情况)和引用[2]中描述的Young GC和Full GC频繁情况,都指向内存泄漏的可能,因此上述步骤是适用的。 生成相关问题: 1. 如何生成和分析Java堆转储文件(Heap Dump)? 2. 除了内存泄漏,还有哪些原因会导致频繁Full GC? 3. 如何通过JVM参数优化减少GC对CPU的影响? 4. 使用哪些工具可以实时监控JVM内存和GC活动? </think>当GC导致CPU资源飙升时,排查内存泄漏需要系统性地分析内存使用模式和对象生命周期。以下是完整的排查: --- ### 排查步骤及方法 #### 1. **确认GC与CPU的关联性** - 使用`top`命令定位高CPU进: ```bash top -H -p <PID> # 查看Java线级CPU占用 ``` - 若发现GC线(如`GC task thread#0`)持续高CPU占用 > 70%,基本确认GC是主因[^2] #### 2. **实时监控GC行为** - 通过`jstat`动态观察GC频率: ```bash jstat -gcutil <PID> 1000 10 # 每秒采样1次,连续10次 ``` - **关键指标**: - `FGC`:Full GC次数(若持续增长则危险) - `OU`:老年代使用率(>80%需警惕) - `YGCT/FGCT`:Young/Full GC耗时(突增表示恶化) #### 3. **堆内存分析(关键步骤)** - **快速筛查大对象**: ```bash jmap -histo:live <PID> | head -20 # 显示实例数最多的前20个类 ``` - 关注`[C`(char[])、`[B`(byte[])等基础类型数组 - 可疑类特征:实例数量异常多且持续增长 - **生成堆转储深入分析**: ```bash jmap -dump:live,format=b,file=heapdump.hprof <PID> ``` - 使用MAT/Eclipse Memory Analyzer加载`heapdump.hprof` - 执行泄漏检测:`Leak Suspects Report` #### 4. **内存泄漏特征分析** - **支配树(Dominator Tree)**: - 查找占用总堆 > 5% 的独立对象 - 检查其引用链,定位非预期的GC Root - 常见泄漏点:静态集合、未关闭连接、线局部变量 - **对象生命周期对比**: | 正常对象 | 泄漏对象 | |----------|----------| | 短周期临时对象 | 长周期无意义对象 | | Young GC可回收 | 晋升到老年代堆积 | | 引用链清晰 | 被静态/缓存强引用 | #### 5. **结合日志定位代码** - 在GC日志中提取触发Full GC的时间戳: ```plaintext 2023-07-01T14:22:01.315+0800: 3.321: [Full GC (Allocation Failure) ... ``` - 关联应用日志,分析该时刻业务操作: ```bash grep "2023-07-01 14:22:01" app.log ``` - 常见泄漏场景:大文件处理、缓存未过期、循环引用 --- ### 内存泄漏修复验证 1. **注入压力测试**: ```bash jmeter -n -t test_plan.jmx -l result.jtl ``` 2. **监控修复效果**: - 老年代内存波动应呈锯齿状(正常回收) - Full GC频率下降 > 90% - CPU占用回归基线水平 > 📌 **经验提示**:约85%的内存泄漏可通过`jmap -histo`快速定位[^1]。若堆转储超过2GB,优先使用`jhat`在线分析避免OOM。 --- ### 排查工具链推荐 | 工具 | 用途 | 关键参数/功能 | |---------------|--------------------------|---------------------------| | `jstat` | 实时GC监控 | `-gcutil`, `-gccapacity` | | `jmap` | 堆内存快照 | `-dump`, `-histo` | | MAT | 堆转储可视化分析 | Dominator Tree, Path to GC Root | | `arthas` | 在线诊断 | `heapdump`, `vmtool` | ---
评论 1
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值