↓Skip to main content
  1. posts/

Jstack实践-线程无限增长导致被容器OOMkilled

·1412 words·3 mins
Java JVM
Table of Contents

现象

容器每隔一段时候就会自动重启，大概一周左右。理由是OOMkilled。 查看jstack日志，发现里面竟有3319个线程在运行。

image.png
image.png

分析

看看这些线程都在做什么？（图表来源于fastthread.io）

image.png
可以看到有1578个pool，和1485个消费线程。而这里就占了90%。所以肯定有点问题。 于是就可以详细看pool和这个消费线程在做啥。 pool基本都是两个两个一组双数增长。而且也看不到什么业务代码。
image.png
消费线程也是两个两个的，一个上行，一个下行。
image.png
那只能从业务代码出发了。 从代码中搜索下行回复消息，找到了
image.png
image.png
image.png
image.png

根因

大致逻辑是，有个设备上下线的接口。

  1. 每隔7分钟调用设备上线接口
  2. 触发iotClient的start(),里面会new IotMqttService()
  3. 然后触发线程池的创建，以及上下行消息的提交
  4. 触发两个监听两个阻塞队列读取上下行消息。

这就造成了线程数不断增长。最终导致超出容器分配的内存而被OOMkilled。

修复

初始思路 设备下线时，触发线程池的关闭。梳理下线逻辑，在内部的一个clear方法，将线程池关掉。

image.png
但是写完，测试的时候发现线程数依旧在涨（这里在测试环境模拟了线上环境，然后通过脚本一直在跑请求），而且我明明都shutdownNow了，还是依旧会有消息线程的增长。
image.png
于是我在while(true)内部增加了中断处理。 但是神奇的是，线程数还是在涨。

于是我在线程池关闭之后，通过一个异步线程打印当前程序的线程数依旧线程名称。发现消息线程确实会被处理掉，但是还是有这个pool-thread。那这个pool-thread是在哪里开启的呢？

image.png
�回到fastthread.io,看到这个pool-thread是通过ScheduledThreadPoo触发的。同样的，代码中大概率是通过newScheduledThreadPool创建的线程池，就搜一下，果然发现了这个。
image.png
不啰嗦了，这个的原因是：创建这个IotMqttService的时候也会初始化一个日志打印的线程池，也会有两个线程在做日志打印的工作。
image.png
于是我把这个改成了单例模式。 到这里，基本上才算清晰， 为啥线程池的shutdownNow不生效？(没有做break处理，shutdownNow只会将正在执行的线程进行中断，而业务上的线程在死循环等待，中断之后又进入了循环) 为啥pool-thread总是双数增长？（消费线程也是个线程池，之后业务设置了名称为消费线程，不然也是pool）

最终成效

image.png
异步打印程序的线程结果
image.png
开了一个watch命令，没20s跑一次请求，跑了一下午，线程数基本都是稳定在105.

总结

线程不断增长问题排查过程总结

  1. top -Hp 查看cpu情况和线程情况
  2. jstack » jstack.log 分析jstack日志（通过fastthread.io分析）
  3. 通过fastthread.io的线程分组查看线程详情。
  4. 通过关键词定位业务逻辑。
  5. 分析业务逻辑，复现&解决问题

注意⚠️ 线程池使用还是要谨慎啊，千万要注意关闭的问题。

遗留待处理问题

一个线程占用多少内存？【1.9g的容器内存，大概可以开启9900多个线程，加上堆内存之类的，一个线程大概几百kb】【csdn上有个人说大概100k，看起来还算可信。https://blog.csdn.net/spytian/article/details/113637759】 如果操作系统内存足够，一个Java程序可以无限增加线程吗？【应该会受JVM堆外内存限制，但是具体堆外内存是多少，怎么设置，我也还不太清楚】

↑