案例解析:线程池使用不当导致的系统崩溃

前几天,发现一台阿里云服务器上的Web服务不可用。远程SSH登录不上,尝试几次登录上去之后,执行命令都显示

-bash: fork: Cannot allocate memory

一看以为是内存泄漏导致溢出。因为执行不了任何命令, 只能通过控制台重启服务器恢复服务。 

 

初步排查

服务恢复后,查看系统日志,linux系统日志路径/var/log/messages,可通过journalctl命令查看,如

journalctl --since="2019-06-12 06:00:00" --until="2019-06-12 10:00:00"

可查看since之后,until之前时间段的日志。除了发现crond[14954]: (CRON) CAN'T FORK (do_command): Cannot allocate memory 这个错误日志,未见其它异常(下面的sshd[10764]: error: fork: Cannot allocate memory应是ssh登录执行命名失败的日志)

linux-log

通过阿里云-云监控-主机监控查看内存使用率指标,这段时间内,内存使用率一直在40%以下,基本可排除内存溢出的可能。

通过搜索查阅到进程数超过操作系统限制可能导致bash: fork: Cannot allocate memory的报错(参考: https://blog.csdn.net/wangshuminjava/article/details/80603847 )。

通过ps -eLf|wc -l查看当前进程线程数(ps -ef只打印进程,ps -eLf会打印所有的线程), 只有1000多个,故障时刻系统到底运行了多少线程已无从得知,只能持续跟进监测。

问题定位

几天后,再次通过ps -eLf|wc -l查看,发现线程数已达16000多个。直接执行ps -eLf可看到大量tomcat进程所产生的线程,猜测是不是线程死锁导致大量线程未完成一直hung在那里。

执行 jstack 进程号 > ~/jstack.txt 命令将进程所运行线程情况打印出来分析,发现大量的WAITING状态的线程,如下

"pool-19-thread-1" #254 prio=5 os_prio=0 tid=0x00007f0b700a6000 nid=0x29a9 waiting on condition [0x00007f0b274df000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006ce3d8790> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

 

根据上述内容可看出线程在等一个条件,并且是在执行LinkedBlockingQueue.take方法的时候,查看该方法的java doc,当队列为空时,该方法将会一直等待直到有元素可用。

/**
 * Retrieves and removes the head of this queue, waiting if necessary
 * until an element becomes available.
 *
 * @return the head of this queue
 * @throws InterruptedException if interrupted while waiting
 */
E take() throws InterruptedException;

  

询问同事在哪里用到了LinkedBlockingQueue,同事回忆起不久前用线程池实现往阿里云OSS服务通过追加的方式上传文件功能,查看代码后发现问题——线程池没有关闭。为了使文件片段保存不存在错乱,每次保存文件时,都new了一个线程池对象, 

ThreadPoolExecutor saveImgThreadPool = new ThreadPoolExecutor(1, 1, 0, TimeUnit.SECONDS, new LinkedBlockingQueue<>());

但处理完后, 没有关闭这个线程池对象,这样线程池仍会通过take方法去取等待队列中是否还有未完成的线程任务,等待队列为空时将会一直等待,这样就导致大量的线程hung在这里了(基本是只要方法被调一次,就会产生一个hung住的线程)。 

延伸

  1. 线程状态为“waiting for monitor entry”:
    意味着它 在等待进入一个临界区 ,所以它在”Entry Set“队列中等待。此时线程状态一般都是 Blocked:
    java.lang.Thread.State: BLOCKED (on object monitor)

  2. 线程状态为“waiting on condition”:
    说明它在等待另一个条件的发生,来把自己唤醒,或者干脆它是调用了 sleep(N)。此时线程状态大致为以下几种:
    java.lang.Thread.State: WAITING (parking):一直等那个条件发生(本文案例即为此种场景);java.lang.Thread.State: TIMED_WAITING (parking或sleeping):定时的,那个条件不到来,也将定时唤醒自己。

  3. 如果大量线程在“waiting for monitor entry”:可能是一个全局锁阻塞住了大量线程。如果短时间内打印的thread dump 文件反映,随着时间流逝,waiting for monitor entry 的线程越来越多,没有减少的趋势,可能意味着某些线程在临界区里呆的时间太长了,以至于越来越多新线程迟迟无法进入临界区。

  4. 如果大量线程在“waiting on condition”:可能是它们又跑去获取第三方资源,尤其是第三方网络资源,迟迟获取不到Response,导致大量线程进入等待状态。所以如果你发现有大量的线程都处在 Wait on condition,从线程堆栈看,正等待网络读写,这可能是一个网络瓶颈的征兆,因为网络阻塞导致线程无法执行。也可能是如本文所提到的,由于程序编写不当所致。





我的个人博客地址:http://blog.jboost.cn
我的头条空间: https://www.toutiao.com/c/user/5833678517/#mid=1636101215791112
我的github地址:https://github.com/ronwxy
我的微信公众号:jboost-ksxy

——————————————————————————————————————

微信公众号
欢迎关注我的微信公众号,及时获取最新分享

posted @ 2019-06-16 20:26  【雨歌】  阅读(9039)  评论(0编辑  收藏  举报