TCP连接不释放，应用产生大量CLOSE_WAIT状态TCP

一、起源

23年元旦期间，大家都沉浸在一片祥和的过节气氛当中。

“滴滴滴”，这头同事的电话响起，具体说些什么我也没太在意，但见同事接完电话之后展现出了一副懊恼夹杂着些许不耐烦的表情。

我不解问道：“怎么了？”

同事：“刚刚运营反馈系统开始刷白屏了，所有的请求一直处于pending状态。”

此刻我的大脑开始飞速旋转，界面白屏？前端是不是有一个初始化的请求？这个初始化的请求有问题导致前端没有往下运行并渲染页面？

我：“已经登陆进系统的用户可以正常使用吗？”

同事：“也不可以”。

那就不是初始化请求失败的问题了。

再往下分析，应用进程应该没有宕机，否则接口会快速响应404。

我：“所有接口都阻塞住了还是单个接口的问题，最近有没有项目发版？”

同事：“运营反馈是所有接口都有阻塞情况，这段时间一直没有发版”。

那就怪了，近期没有发版，而且所有接口均有问题。

到此，基本可以判定出，这个问题与业务无关，而是类似基础设施出现问题导致了，比如网络问题、Java GC问题、线程池线程短缺出现业务饥饿问题等。

这种问题勾起了我的兴趣，我决定自己上手问题，开始排查…

二、表象

打开系统，发现浏览器发出的接口确实都处于“pending”状态。（Ps：pending是浏览器发出请求之后的一种状态，代表该请求还未得到服务器响应，如果接口RT延迟高，你就有可能经常看到这种状态）；

接口处于pending状态，我在本地使用telnet ip port命令连接应用服务器端口也是正常的，到此说明网络与应用进程都是完好的。

三、排查

打开监控系统查看了Java GC耗时、次数两项指标，发现和平时也没什么不一样。

查看了系统调用量发现与往常相似，没有什么流量突刺。

同事查看了那段时间的系统日志也未发现明显的错误。

我手里的鼠标一直向下滑动着，我和同事紧张的看着电脑，紧盯着各项指标，希望能看出些端倪，并能以此为突破口。

果然，还是看到了…

下图是近几天的TCP连接数曲线图：

TCP涨势图.jpeg

发现TCP连接一直处于只涨不降的趋势（除了中间几次的人为重启机器）。

我进入服务器，熟练的敲起Linux命令：

[root] $ **netstat -na | grep '8089' | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
LISTEN 8
CLOSE_WAIT 35
ESTABLISHED 108
SYN_SENT 1
TIME_WAIT 9**[root] $ netstat -ntp | grep 'CLOSE_WAIT'
tcp 1 0 本机ip:端口  nginx机器  CLOSE_WAIT  pid/java
....

观察了十分钟，发现CLOSE_WAT状态的TCP连接数一直处于增长的状态。并且观察到所有的CLOSE_WAIT状态的TCP都是与Nginx建立的，问了运维同学，这台Nginx是这台后端应用的代理。

同事：“啊，原来是TCP连接数捣鬼，一直上涨但不释放”。

这一点和浏览器发出的接口一直处于Pending状态刚好吻合起来了。一定是代码出现了什么问题，导致接口延迟上升，所有的HTTP请求映射到底层就是TCP连接，应用服务器一直没有返回内容，那么TCP自然也不会释放了（这里我们先不考虑现代HTTP协议的KeepAlive机制）。

只见同事为了止血抓紧去重启机器了，好让这些TCP连接被强制关闭。

但我还有一点疑问，TCP未能及时释放确实有问题不假，但即便是这样，区区500个TCP连接，也不至于达到操作系统的阈值，要知道操作系统对端口的限制理论上可以达到65535个。

那一定是有一个短板的中间件因达到了阈值而限制了整个系统，很快我便想到了Tomcat，因为Tomcat一定是每个业务接口都绕不过的中间件。

虽然机器已经重启了，但我们有服务治理相关的平台可以调出任意一个时间点的线程状态，不看不知道，一看吓一跳，所有以“http-nio-xxx”为前缀的线程全部阻塞在方法：SocketInputStream.read0方法中。熟悉这个前缀线程的人都知道，这是Tomcat线程池。

我：”查一下日志，看看接口AOP有没有捕捉到请求信息？“

同事：“捕捉到了”

我：“随机抽取几个请求，看看接口AOP是否捕捉到了接口响应信息”

同事抓紧去查了，不一会儿惊讶的说道：“老朱，还真有很多请求接口响应AOP没有捕获到，那就是说这些请求一直没有处理完”。

同事又说道：“老朱，这个项目比较特殊，项目中所有的接口基本只做了透传的事情，项目只是做简单的数据加工，然后请求其他系统，最后针对结果集再进行过滤、转换返回给前端”

我：“啊，原来是这样，目前使用的HTTP客户端是什么？”

同事：“Apache HttpClient”

我：“Apache HttpClient？三个超时时间都设置了吧？“

同事：“嗯，都设置了，connectTimeout、socketTimeout、connectionRequestTimeout都根据项目的性质调试过了，并且数据流也都妥善处理了”

我有些不解，所有的超时时间都设置好了，那为什么还会有大量的Tomcat线程阻塞在SocketInputstream.read0方法中呢，最终导致TCP持续飙高。

我和同事都陷入了困境，进入两难处境，不知道如何继续排查，机器重启确实可以强制释放TCP但是这方法治标不治本。

同事：“啊，这，怎么会这样”

我：“怎么了？！吞吞吐吐”

同事：“我记得之前明明在这些应用里都加了接口AOP日志，刚刚看到我们项目有日志，但是其他系统中居然没有日志…

至此我有个大胆的猜测，请求进入项目之后，项目加工请求并转发给其他项目，但转发给系统项目的这段网络出现了什么问题（因为其他系统并未收到请求），又因为种种原因导致超时时间并未生效，慢慢的项目中所有Tomcat线程都阻塞在了SocketInputstream中的read0方法中，最后Tomcat无空闲线程可去处理用户提交的新的请求。

但是什么情况下Apache HttpClient中的超时时间不生效呢？

直到我看到了一篇JDK官网说明：

Bug ID: JDK-8172578 SocketInputStream.socketRead0 can hang even with soTimeout set

SocketInputStream.socketRead0 can hang even with soTimeout set

在第二篇文章中有详细描述了SocketTimeOut参数失效的原因，大致意思是：因为OS select方法存在虚假唤醒的问题导致线程提前进行读取，但又因为并没有实际数据因此造成了读取阻塞。

而我们的JDK版本是1.8.0_91，也就是低于JDK修复版本，当OS发出虚假唤醒之后，导致Java线程进入阻塞读取状态，最终导致socketTimeout失效。

事情到这就解释的通了，我再来根据现象与各项指标结合起来从头到尾的阐述一波。

应用拓扑图.png

这里先祭出项目的拓扑图。

应用A是这次案发地点，应用A的大多数功能只是做请求透传工作，将用户请求的参数做过滤、筛选、添油加醋发送给应用B。

根据上述的拓扑性质，以应用A为中心会有两段请求，这里标识为A段、B段。

案发时间前几个小时，起初系统稳如老狗。应用A稳定的处理着Nginx转发来的前端请求，并包装发送给应用B，然后将应用B返回来的数据进行筛选、处理然后返回给用户。

然而好景不长，B段出现了一些网络丢包、抖动等情况变得开始不稳定了，搭配上JDK8U152版本之前可能会受到操作系统的select虚假唤醒的情况，慢慢的Tomcat很多线程都阻塞在了SocketInputstream的read0方法上，这一点和之前看到的线程Dump信息一致。

看了眼项目对Tomcat的线程数配置：server.tomcat.max-threads=**400**，而线程Dump出的信息中刚好有400个线程阻塞在了read0方法中。

嗯，没错，就是这样，最后Tomcat成为了整个项目的瓶颈。

四、解决

知道了，问题就非常方便解决了，我主要采取了三个措施：

1. 将项目中使用的BIO HttpClient化成NIO的方式：HttpAsyncClient
2. 升级JDK为JDK8u152版本
3. 添加耗时兜底方案，若超过SocketTimeout时间，应用A请求B应用还未结束，则手动关闭TCP连接，Tomcat主线程继续向下运行

其中第二点不用说，我通过一段伪代码来说明一下1和3.

public static String getHttpClientResult(CloseableHttpAsyncClient asyncHttpClient, HttpRequestBase httpMethod) throws IOException {String content = "";        // TCP强制断开标志boolean abortFlag = true;HttpResponse response = null;// 执行请求Future<HttpResponse> httpResponseFuture = asyncHttpClient.execute(httpMethod, null);try {httpResponse = httpResponseFuture.get(SOCKET_TIMEOUT, TimeUnit.MILLISECONDS);abortFlag = false;// 获取返回结果if (httpResponse.getEntity() != null) {content = EntityUtils.toString(httpResponse.getEntity(), ENCODING);}} catch (InterruptedException e) {// 线程被打断，重新设置标志并且向下运行Thread.currentThread().interrupt();} catch (ExecutionException e) {// http执行异常，包括readTimeOut、connectTimeOutlog.error("当前线程:{},请求异常,发送TCP RST包强制断开", Thread.currentThread().getName());} catch (TimeoutException e) {/*** future get 超时 兜底方案，避免主线程阻塞在read方法中* @see java.net.SocketInputStream#socketRead0(java.io.FileDescriptor, byte[], int, int, int)* 若超时则发送RST包以强制连接双方断开TCP*/log.error("当前线程:{},超时:{}秒,仍未获取到数据,发送RST包", Thread.currentThread().getName(), SOCKET_TIMEOUT);} finally {if (abortFlag) {httpMethod.abort();}// 释放资源if (!Objects.isNull(httpResponse)&& !Objects.isNull(httpResponse.getEntity())&& !Objects.isNull(httpResponse.getEntity().getContent())) {httpResponse.getEntity().getContent().close();}}return abortFlag ? null : content;}

代码优化完毕，赶紧发版，目前我的这位同事在也没有被运维‘骚扰’过了，目前TCP升降趋势稳定喜人 ，如下：

修复后的TCP涨势图.jpeg