一次 close_wait 问题的深度解析

原创潘志超 Qunar技术沙龙 2019-11-08

背景

前些天 QA 同学为保证服务的高可用，为所有线上机器的各项系统指标加了报警，其中就包括了 close_wait 状态的 TCP 连接数报警，结果当天晚上就非常热闹，报警信息、报警电话一波接一波，最后不得不暂时关掉 close_wait 指标报警，后续由各业务线修复了自己的问题之后再重启报警，其中就有几个系统是我们的，几天的探索之后发现是一个非常 low 的问题，本可以快速修复，只因漏看了一行代码，过程中甚至怀疑 apache-httpclient 有 bug，导致了后续花了比较多的精力在上面。虽然如此，回想起问题的排查过程也算颇有收获，所以决定整理一下为自己做个总结，也希望对他人有所帮助。

现象

处于 close_wait 状态的 TCP 连接长期维持在 35 左右，长期处于 close_wait 状态的连接不仅无法提供服务，还会占用 http 客户端和服务端的连接资源，极限情况下导致无法创建连接，严重影响业务。因为之前处理过因为防火墙问题，导致 http 客户端服务器 close_wait 偏高，最终影响给用户退款的 case，所以 close_wait 问题再次出现引起了大家高度重视。以下是出问题是问题机器的 close_wait 监控：

抛出问题

1）TCP 协议是如何工作的，何时会产生 close_wait？

2）TCP 报文发送与 java 代码的关系？

3）为什么会产生 close_wait？

4）close_wait 量为什么每隔一段时间就会断崖式的往下掉？

5）apache httpclient 连接池是如何工作的？

探索之旅

通过报文认识 TCP

首先第一个问题，TCP 协议是如何工作的，主要分三步：

1）三次握手建立连接（下图中 1-3 行）

2）在已建立连接上执行数据传输（下图中 4-7 行）

3）四次挥手关闭连接（下图中 8-11 行）

tcpdump 是分析 TCP 协议的利器，这里我们使用 tcpdump 直接看报文数据来进一步加深理解，下面是通过 tcpdump 工具获取到的一个 TCP 连接整个生命周期的报文（这里先不用关注报文时间，后续会有说明）。

17:51:16.801932 IP xxx.xxx.xxx.93.9992> xxx.xxx.xxx.100.36666: Flags[S], seq 3004848363, win 14600, options [mss 1460,nop,nop,sackOK,nop,wscale 9], length 0
17:51:16.802069 IP xxx.xxx.xxx.100.36666> xxx.xxx.xxx.93.9992: Flags[S.], seq 2423612252, ack 3004848364, win 14600, options [mss 1460,nop,nop,sackOK,nop,wscale 9], length 0
17:51:16.802087 IP xxx.xxx.xxx.93.9992> xxx.xxx.xxx.100.36666: Flags[.], ack 1, win 29, length 0
17:51:17.803516 IP xxx.xxx.xxx.93.9992> xxx.xxx.xxx.100.36666: Flags[P.], seq 1:37, ack 1, win 29, length 36
17:51:17.803709 IP xxx.xxx.xxx.100.36666> xxx.xxx.xxx.93.9992: Flags[.], ack 37, win 29, length 0
17:51:18.804265 IP xxx.xxx.xxx.93.9992> xxx.xxx.xxx.100.36666: Flags[P.], seq 37:65, ack 1, win 29, length 28
17:51:18.804462 IP xxx.xxx.xxx.100.36666> xxx.xxx.xxx.93.9992: Flags[.], ack 65, win 29, length 0
17:51:19.804768 IP xxx.xxx.xxx.93.9992> xxx.xxx.xxx.100.36666: Flags[F.], seq 65, ack 1, win 29, length 0
17:51:19.844675 IP xxx.xxx.xxx.100.36666> xxx.xxx.xxx.93.9992: Flags[.], ack 66, win 29, length 0
17:51:22.805256 IP xxx.xxx.xxx.100.36666> xxx.xxx.xxx.93.9992: Flags[F.], seq 1, ack 66, win 29, length 0
17:51:22.805280 IP xxx.xxx.xxx.93.9992> xxx.xxx.xxx.100.36666: Flags[.], ack 2, win 29, length 0

要了解 TCP 通讯过程，TCP 标志位不得不提，共 6 位，代表含义如下表，其中除了第一位之外，上面的 case都会用到。

上面是一个典型的TCP三次握手->传输数据->四次挥手的过程，详细过程如下：

第 1 行：第一次握手，93 向 100 发送[S]同步报文，seq=3004848363，创建连接开始

第 2 行：第二次握手，100 向 93 发送同步[S.]同步+确认报文，seq=2423612252，ack=3004848363+1,93tcp 连接状态为 SYNSENT，100 tcp 连接状态为 SYNRCVD

第 3 行：第三次握手，93 发送[S]确认报文，ack=1（网上有些文章说 ack 为2423612252+1 是不对的）连接建立成功

第 4 行：数据传输，93 向 100 发送[P.]数据推送+同步报文，seq=1:37，前闭后开，推送 tcp body 中第 1-36 个字节内容，即 length=36，推送数据为：[05:51:17 802 hello ,i am zhichao.pan]，刚好 36 byte

第 5 行：100 向 93 发送[.]数据确认报文，ack=37

第 6 行：同第 4 行

第 7 行：同第 5 行

第 8 行：第一次挥手，93 向 100 发送[F.]主动关闭连接报文，seq=65,ack=1

第 9 行：第二次挥手，100 向 93 发送[.]确认报文，ack 65+1=66

第10 行：第三次挥手，100 向 93 发送[F.]主动关闭连接报文，seq=1,ack=66

第 11 行：第四次挥手，93 向 100 发送[.]确认报文，ack 1+1=2，连接关闭成功

同时伴随以上报文发送，93 和 100 两台机器的 TCP 连接状态如下：

那么 close_wait 何时产生呢？

看上面的 TCP 报文关闭流程可知，当被动关闭方收到主动关闭放 F 报文并回复 ACK 后，TCP 状态为 close_wait，直到被动关闭方发送 F 报文后 close_wait 变更为 LASTACK，理论上这个状态持续的时间非常短，基本很难监控到，除非被动关闭方后续并未立即发起F报文。即只有我们的服务作为被动关闭方未及时发送 F 报文时 close_wait 问题出现，那么如何使用 java 代码关闭 TCP 连接呢？

TCP 报文发送与 java 代码的关系

记一次CLOSE_WAIT问题排查 https://mp.weixin.qq.com/s/nEyaJ9yeyCsMGeb0rvd3SA

记一次CLOSE_WAIT问题排查

原创张兆原 Qunar技术沙龙 2019-04-24