线上大量CLOSE_WAIT缘由深刻分析

这一次重启真的没法解决问题了：一次 MySQL 主动关闭，致使服务出现大量 CLOSE_WAIT 的全流程排查过程。

近日遇到一个线上服务 socket 资源被不断打满的状况。经过各类工具分析线上问题,定位到问题代码。这里对该问题发现、修复过程进行一下复盘总结。

先看两张图。一张图是服务正常时监控到的 socket 状态，另外一张固然就是异常啦！

图一：正常时监控

图二：异常时监控

从图中的表现状况来看，就是从 04:00 开始，socket 资源不断上涨，每一个谷底时重启后恢复到正常值，而后继续不断上涨不释放，并且每次达到峰值的间隔时间愈来愈短。

重启后，排查了日志，没有看到 panic ，此时也就没有进一步检查，真的觉得重启大法好。

状况说明

该服务使用Golang开发，已经上线正常运行将近一年，提供给其它服务调用，主要底层资源有DB/Redis/MQ。

为了后续说明的方便，将服务的架构图进行一下说明。

图三：服务架构

架构是很是简单。

问题出如今早上 08:20 左右开始的，报警收到该服务出现 504，此时第一反应是该服务长时间没有重启（快两个月了），可能存在一些内存泄漏，没有多想直接进行了重启。也就是在图二第一个谷底的时候，通过重启服务恢复到正常水平（重启真好用，开心）。

将近 14:00 的时候，再次被告警出现了 504 ，当时心中略感不对劲，但因为当天刚好有一场大型促销活动，所以先立马再次重启服务。直到后续大概过了1小时后又开始告警，连续几回重启后，发现须要重启的时间间隔愈来愈短。此时发现问题毫不简单。这一次重启真的解决不了问题老，所以立马申请机器权限、开始排查问题。下面的截图所有来源个人重现demo，与线上无关。

发现问题

出现问题后，首先要进行分析推断、而后验证、最后定位修改。根据当时的表现是分别进行了如下猜测。

ps：后续截图所有来源本身本地复现时的截图

推断一

socket 资源被不断打满，而且以前从未出现过，今日忽然出现， 怀疑是否是请求量太大压垮服务

通过查看实时 qps 后，放弃该想法，虽然量有增长，但依然在服务器承受范围（远远未达到压测的基准值）。

推断二

两台机器故障是同时发生，重启一台，另一台也会获得缓解，做为独立部署在两个集群的服务很是诡异

有了上面的的依据，推出的结果是确定是该服务依赖的底层资源除了问题，要否则不可能独立集群的服务同时出问题。

因为监控显示是 socket 问题，所以经过 netstat 命令查看了当前tcp连接的状况（本地测试，线上实际值大的多）

/go/src/hello # netstat -na | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
LISTEN 2
CLOSE_WAIT 23 # 很是异常
TIME_WAIT 1

发现绝大部份的连接处于 CLOSE_WAIT 状态，这是很是难以想象状况。而后用 netstat -an 命令进行了检查。

图四：大量的CLOSE_WAIT

CLOSED 表示socket链接没被使用。
LISTENING 表示正在监听进入的链接。
SYN_SENT 表示正在试着创建链接。
SYN_RECEIVED 进行链接初始同步。
ESTABLISHED 表示链接已被创建。
CLOSE_WAIT 表示远程计算器关闭链接，正在等待socket链接的关闭。
FIN_WAIT_1 表示socket链接关闭，正在关闭链接。
CLOSING 先关闭本地socket链接，而后关闭远程socket链接，最后等待确认信息。
LAST_ACK 远程计算器关闭后，等待确认信号。
FIN_WAIT_2 socket链接关闭后，等待来自远程计算器的关闭信号。
TIME_WAIT 链接关闭后，等待远程计算器关闭重发。

而后开始重点思考为何会出现大量的mysql链接是 CLOSE_WAIT 呢？为了说清楚，咱们来插播一点TCP的四次挥手知识。

TCP四次挥手

咱们来看看 TCP 的四次挥手是怎么样的流程：

图五：TCP四次挥手

用中文来描述下这个过程：

Client: 服务端大哥，我事情都干完了，准备撤了，这里对应的就是客户端发了一个FIN

Server：知道了，可是你等等我，我还要收收尾，这里对应的就是服务端收到 FIN 后回应的 ACK

通过上面两步以后，服务端就会处于 CLOSE_WAIT 状态。过了一段时间 Server 收尾完了

Server：小弟，哥哥我作完了，撤吧，服务端发送了FIN

Client：大哥，再见啊，这里是客户端对服务端的一个 ACK

到此服务端就能够跑路了，可是客户端还不行。为何呢？客户端还必须等待 2MSL 个时间，这里为何客户端还不能直接跑路呢？主要是为了防止发送出去的 ACK 服务端没有收到，服务端重发 FIN 再次来询问，若是客户端发完就跑路了，那么服务端重发的时候就没人理他了。这个等待的时间长度也很讲究。

Maximum Segment Lifetime 报文最大生存时间，它是任何报文在网络上存在的最长时间，超过这个时间报文将被丢弃

这里必定不要被图里的 client／server 和项目里的客户端服务器端混淆，你只要记住：主动关闭的一方发出 FIN 包（Client），被动关闭（Server）的一方响应 ACK 包，此时，被动关闭的一方就进入了 CLOSE_WAIT 状态。若是一切正常，稍后被动关闭的一方也会发出 FIN 包，而后迁移到 LAST_ACK 状态。

既然是这样， TCP 抓包分析下：

/go # tcpdump -n port 3306
# 发生了 3次握手
11:38:15.679863 IP 172.18.0.5.38822 > 172.18.0.3.3306: Flags [S], seq 4065722321, win 29200, options [mss 1460,sackOK,TS val 2997352 ecr 0,nop,wscale 7], length 0
11:38:15.679923 IP 172.18.0.3.3306 > 172.18.0.5.38822: Flags [S.], seq 780487619, ack 4065722322, win 28960, options [mss 1460,sackOK,TS val 2997352 ecr 2997352,nop,wscale 7], length 0
11:38:15.679936 IP 172.18.0.5.38822 > 172.18.0.3.3306: Flags [.], ack 1, win 229, options [nop,nop,TS val 2997352 ecr 2997352], length 0

# mysql 主动断开连接
11:38:45.693382 IP 172.18.0.3.3306 > 172.18.0.5.38822: Flags [F.], seq 123, ack 144, win 227, options [nop,nop,TS val 3000355 ecr 2997359], length 0 # MySQL负载均衡器发送fin包给我
11:38:45.740958 IP 172.18.0.5.38822 > 172.18.0.3.3306: Flags [.], ack 124, win 229, options [nop,nop,TS val 3000360 ecr 3000355], length 0 # 我回复ack给它

... ... # 原本还须要我发送fin给他，可是我没有发，因此出现了close_wait。那这是什么缘故呢？

src > dst: flags data-seqno ack window urgent options

src > dst 代表从源地址到目的地址
flags 是TCP包中的标志信息,S 是SYN标志, F(FIN), P(PUSH) , R(RST) "."(没有标记)
data-seqno 是数据包中的数据的顺序号
ack 是下次指望的顺序号
window 是接收缓存的窗口大小
urgent 代表数据包中是否有紧急指针
options 是选项

结合上面的信息，我用文字说明下：MySQL负载均衡器 给个人服务发送 FIN 包，我进行了响应，此时我进入了 CLOSE_WAIR 状态，可是后续做为被动关闭方的我，并无发送 FIN，致使我服务端一直处于 CLOSE_WAIR 状态，没法最终进入 CLOSED 状态。

那么我推断出现这种状况可能的缘由有如下几种：

1. 负载均衡器 异常退出了，

   这基本是不可能的，他出现问题绝对是大面积的服务报警，而不只仅是我一个服务

2. MySQL负载均衡器 的超时设置的过短了，致使业务代码尚未处理完，MySQL负载均衡器 就关闭tcp链接了

   这也不太可能，由于这个服务并无什么耗时操做，固然仍是去检查了负载均衡器的配置，设置的是60s。

3. 代码问题，MySQL 链接没法释放

   目前看起来应该是代码质量问题，加之本次数据有异常，触发到了之前某个没有测试到的点，目前看起来颇有多是这个缘由

查找错误缘由

因为代码的业务逻辑并非我写的，我担忧一时半会看不出来问题，因此直接使用 perf 把全部的调用关系使用火焰图给绘制出来。既然上面咱们推断代码中没有释放mysql链接。无非就是：

1. 确实没有调用close
2. 有耗时操做（火焰图能够很是明显看到），致使超时了
3. mysql的事务没有正确处理，例如：rollback 或者 commit

因为火焰图包含的内容太多，为了让你们看清楚，我把一些没必要要的信息进行了折叠。

图六：有问题的火焰图

火焰图很明显看到了开启了事务，可是在余下的部分，并无看到 Commit 或者是Rollback 操做。这确定会操做问题。而后也清楚看到出现问题的是：

MainController.update 方法内部，话很少说，直接到 update 方法中去检查。发现了以下代码：

func (c *MainController) update() (flag bool) {
    o := orm.NewOrm()
    o.Using("default")
    
    o.Begin()
    nilMap := getMapNil()
    if nilMap == nil {// 这里只检查了是否为nil，并无进行rollback或者commit
        return false
    }

    nilMap[10] = 1
    nilMap[20] = 2
    if nilMap == nil && len(nilMap) == 0 {
        o.Rollback()
        return false
    }

    sql := "update tb_user set name=%s where id=%d"
    res, err := o.Raw(sql, "Bug", 2).Exec()
    if err == nil {
        num, _ := res.RowsAffected()
        fmt.Println("mysql row affected nums: ", num)
        o.Commit()
        return true
    }

    o.Rollback()
    return false
}

至此，所有分析结束。通过查看 getMapNil 返回了nil，可是下面的判断条件没有进行回滚。

if nilMap == nil {
    o.Rollback()// 这里进行回滚
    return false
}

总结

整个分析过程仍是废了很多时间。最主要的是主观意识太强，以为运行了一年没有出问题的为何会忽然出问题？所以一开始是质疑 SRE、DBA、各类基础设施出了问题（人老是先怀疑别人）。致使在这上面费了很多时间。

理一下正确的分析思路：

1. 出现问题后，立马应该检查日志，确实日志没有发现问题；
2. 监控明确显示了socket不断增加，很明确立马应该使用 netstat 检查状况看看是哪一个进程的锅；
3. 根据 netstat 的检查，使用 tcpdump 抓包分析一下为何链接会被动断开（TCP知识很是重要）；
4. 若是熟悉代码应该直接去检查业务代码，若是不熟悉则可使用 perf 把代码的调用链路打印出来；
5. 不管是分析代码仍是火焰图，到此应该可以很快定位到问题。

那么本次究竟是为何会出现 CLOSE_WAIR 呢？大部分同窗应该已经明白了，我这里再简单说明一下：

因为那一行代码没有对事务进行回滚，致使服务端没有主动发起close。所以 MySQL负载均衡器 在达到 60s 的时候主动触发了close操做，可是经过tcp抓包发现，服务端并无进行回应，这是由于代码中的事务没有处理，所以从而致使大量的端口、链接资源被占用。在贴一下挥手时的抓包数据：

# mysql 主动断开连接
11:38:45.693382 IP 172.18.0.3.3306 > 172.18.0.5.38822: Flags [F.], seq 123, ack 144, win 227, options [nop,nop,TS val 3000355 ecr 2997359], length 0 # MySQL负载均衡器发送fin包给我
11:38:45.740958 IP 172.18.0.5.38822 > 172.18.0.3.3306: Flags [.], ack 124, win 229, options [nop,nop,TS val 3000360 ecr 3000355], length 0 # 我回复ack给它

但愿此文对你们排查线上问题有所帮助。为了便于帮助你们理解，下面附上正确状况下的火焰图与错误状况下的火焰图。你们能够自行对比。

• 正确状况下的火焰图
• 错误状况的火焰图

我参考的一篇文章对这种状况提出了两个思考题，我以为很是有意义，你们本身思考下：

1. 为何一台机器几百个 CLOSE_WAIR 就致使不可继续访问？咱们不是常常说一台机器有 65535 个文件描述符可用吗？
2. 为何我有负载均衡，而两台部署服务的机器确几乎同时出了 CLOSE_WAIR ?

参考文章：

1. 又见CLOSE_WAIT
2. TCP 4-times close

我的公众号：dayuTalk