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

背景

一个项目文件存储服务选型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