SpringBoot工程假死,如何揪出幕后真凶的?

工作中经常会遇到程序不响应,但是进程依然存活的现象。原因有很多,比如

  1. 内存、CPU占满了(500,连接超时)
  2. 磁盘满了(500,连接超时)
    今天笔者遇到的不是前两种,原因也很稀奇,tomcat线程池耗尽了,导致500连接超时。

我们是一个spring boot工程,对外提供rest接口服务,但是隔三差五的就会出现500连接超时的现象。

排除了内存、CPU、磁盘占满的case后,有个同事无意中发现这台机器出现了大量的网络连接CLOSE_WAIT。查询资料后得知,当一个请求方主动发起close连接,但是服务方还没有返回ack这个时间差,连接状态就是close_wait。这是底层tcp的解释。

按说这个时间差是很短的,不足以让整个应用不能对外响应,除非一种情况,那就是某个时刻并发量达到了tomcat的处理请求的极限,同一时间,整个处理请求的线程池全部被占用,并且等待close。刚好我们应用基本符合这个场景。

笔者解决思路是,通过jstack查询线程信息,看http究竟阻塞在哪里了

ps -ef |grep `pwd` 
jstck $PID > stack.txt

先找到该进程的pid,然后通过jstack命令导出线程信息。

在stack.txt中搜索DeadThread无果。继续搜索BLOCKED,发现了大量线程阻塞。

springboot项目关闭hive连接池 springboot 连接池 耗尽_blocked

grep "BLOCKED" -C 3 |grep "http-nio-exec"

springboot项目关闭hive连接池 springboot 连接池 耗尽_blocked_02


http-nio-xx-exec-是tomcat处理请求的线程名称,可以看出,大多数线程都被blocked。这就是发生假死的根源。

线程信息里面也可以看到栈信息,明确告诉我们阻塞发生在了代码哪一行。跟进代码果然,代码中请求了两个已经ping不通的地址。

修改代码后,发布到开发环境,继续观察CLOSE_WAIT情况:

lsof -i:8091 |grep "CLOSE_WAIT" |wc -l

统计close_wait的连接数量

修改前是67,而且还在增长。修改后变成了0。基本可以确定close_wait的问题已经解决了。