这次重启确实解决不了问题：MySQL被主动关闭，导致服务出现大量CLOSE_WAITs。最近遇到一个在线服务的socket资源不断被占满的情况。利用各种工具分析线上问题，定位问题代码。下面是问题发现和修复过程的总结。先看两张图。一张图是服务正常时监控的socket状态，另一张图当然是异常了！图一：正常时间的监控图二：异常时间的监控从图中的表现来看，是从04:00开始，socket资源持续上升，每次谷底重启后，又恢复到正常值，并且然后继续上升而不释放，并且每个峰值之间的间隔越来越短。重启后查看日志，没有看到panic，所以这时候就没有再查看了。真的觉得重启就好了。情况显示该服务是用Golang开发的，已经正常运行了将近一年。它是为其他服务调用而提供的。主要的底层资源是DB/Redis/MQ。为了后续的解释方便，这里描述一下服务的架构图。图3：服务架构该架构非常简单。问题在早上08:20左右开始。警报收到来自服务的504。这时候第一反应是服务已经很久没有重启了（快两个月了），可能会出现一些内存泄露，所以也没多想。重新启动。也就是图2第一个谷底，重启服务后恢复正常（重启真是好用，开心）。将近14:00，我又被警察拨通了504。当时就觉得有点不对劲，但是因为那天正好有大型促销活动，所以立马又重启了服务。直到大约一个小时后，警报才再次响起。连续重启几次后，发现重启的时间间隔越来越短。这个时候发现问题并不容易。这次重启确实解决不了问题，于是马上申请机器权限开始排查问题。以下截图均来自本人转载demo，与线上无关。发现问题后，首先要进行分析推断，然后进行验证，最后定位修改。根据当时的表现，分别做出以下推测。ps：后续所有截图均来自本人本地重现截图。推断是一个socket资源不断被占满，之前没有出现过。今天突然出现了。我怀疑该服务被太多请求淹没了。查看了实时qps后，放弃了idea虽然增加了，但是还在服务器的承受范围内（远低于压力测试的基准值）。推测是两台机器的故障同时发生，重启一台，另一台就会缓解。作为一个独立部署在两个集群中的服务，很奇怪。有了上面的基础，启动的结果一定是服务依赖了。除了底层资源有问题，否则独立集群的服务不可能同时出现问题。由于监控显示是socket问题，所以我通过netstat命令查看了当前的tcp连接状态（本地测试，网上实际值要大很多）/go/src/hello#netstat-na|awk'/^tcp/{++S[$NF]}END{for(ainS)printa,S[a]}'LISTEN2CLOSE_WAIT23#非常异常TIME_WAIT1发现大部分链接都在CLOSE_WAIT状态，这是非常不可思议的。然后用netstat-an命令查看。图4：大量的CLOSE_WAITCLOSED表示没有使用socket连接。LISTENING意味着监听传入的连接。SYN_SENT表示尝试建立连接。SYN_RECEIVED用于连接初始同步。ESTABLISHED表示连接已经建立。CLOSE_WAIT表示远程计算机关闭连接，正在等待套接字连接关闭。FIN_WAIT_1表示socket连接已关闭，正在关闭连接。CLOSING先关闭本地socket连接，再关闭远程socket连接，最后等待确认。LAST_ACK在远程计算机关闭后等待确认信号。FIN_WAIT_2套接字连接关闭后，等待远程计算机的关闭信号。TIME_WAIT连接关闭后，等待远程计算机关闭并重新发送。然后开始重点思考为什么大量的mysql连接都是CLOSE_WAIT？为了说清楚，我们插一点TCP的四次挥手的知识。TCP挥手四次我们来看看TCP的四次挥手的过程：图5：TCP挥手四次用中文描述这个过程：客户端：服务器大哥，我搞定了，准备退出。这对应客户端发送一个FINServer：知道了，不过你等着我，我得做完了。这对应服务器收到FIN后响应的ACK。经过以上两步，服务器会处于CLOSE_WAIT状态。一段时间后，服务器完成整理。服务员：哥，哥，我说完了。我们撤吧。服务端发来FINClient：兄弟，再见。这是从客户端到服务器的ACK。在此之后，服务器可以跑掉，但客户端还没有工作。为什么？client还要等2MSL的时间，为什么client跑不掉呢？主要是为了防止服务器收不到发送的ACK，服务器重新发送FIN再次询问。如果client发完就跑了，服务端再发的时候就没人理会了。等待时间的长短也很有讲究。MaximumSegmentLifetime消息的最长生存时间。它是任何消息在网络上存在的最长时间。在此时间之后，消息将被丢弃。不要被图片中的client/server和项目中的client-server搞混了，你只需要记住：主动关闭的一方发送一个FIN包（Client），被动关闭的一方（Server）回应一个ACK包。此时被动关闭的一方进入CLOSE_WAIT状态。如果一切顺利，后面被被动关闭的一方也会发出一个FIN包，然后转移到LAST_ACK状态。既然如此，分析一下TCP抓包：/go#tcpdump-nport3306#3handshakesoccurred11:38:15.679863IP172.18.0.5.38822>172.18.0.3.3306:Flags[S],seq4065722321,win29200，选项[mss1460，sackOK，TSval2997352ecr0，nop，wscale7]，长度011：38：15.679923IP172.18.0.3.3306>172.18.0.5.38822：标志[S.]，seq719048ack4065722322,win28960,options[mss1460,sackOK,TSval2997352ecr2997352,nop,wscale7],length011:38:15.679936IP172.18.0.5.38822>172.18.0.3,3acks[1,optionswin229[nop,nop,TSval2997352ecr2997352],length0#mysql主动断开链接11:38:45.693382IP172.18.0.3.3306>172.18.0.5.38822:Flags[F.],seq123,ack144,win227,options[nop,nop,TSval3000355ecr2997359],length0#MySQL负载均衡器发送fin包给我11:38:45.740958IP172.18.0.5.38822>172.18.0.3.3306:Flags[.],ack124,win229,options[nop,nop,TSval3000360ecr3000355],length0#我回复ack给它......#我还需要发送fin给他，我没发，就出现了close_wait。那么是什么原因呢？src>dst:flagsdata-seqnoackwindowurgentoptionssrc>dst表示从源地址到目的地址flags是TCP包中的标志信息，S是SYN标志，F(FIN)，P(PUSH)，R(RST)""."（无标记）data-seqno为数据包中数据的序号ack为下一个期望序号window为接收缓冲区的窗口大小urgent表示是否有紧急指针数据包选项中是以上信息的组合，我用文字解释一下：MySQL负载均衡器向我的服务发送了一个FIN包，我回应了。这时候我进入了CLOSE_WAIR状态，但是我作为被动关闭方，没有发送FIN，导致我的服务器一直处于CLOSE_WAIR状态，无法最终进入CLOSED状态。那么我推断出现这种情况的可能原因如下：负载均衡器异常退出，基本不可能.问题肯定是大型服务告警，不仅仅是我的服务MySQL负载均衡服务器的超时设置太短，MySQL负载均衡器在处理业务代码之前就关闭了tcp连接。这也是不太可能的，因为这个服务没有任何耗时的操作。当然，检查负载均衡器的配置是否设置为60s。代码问题，MySQL连接无法释放。目前看来是代码质量问题。另外，这次数据出现了异常，触发了一个之前没有测试过的点。看来很有可能就是这个原因。查找错误原因是由于代码的业务逻辑不是我写的。担心一时半会看不出问题所以直接用perf把所有的调用关系用火焰图画出来。从上面我们推断mysql连接没有在代码中释放。无非就是：确实有一个没有调用close的耗时操作（火焰图可以看得很清楚），导致对超时的mysql事务处理不正确，比如：rollback或者犯罪。因为火焰图包含的内容太多，为了让大家看的清楚，我把一些不需要的信息给折掉了。图6：有问题的火焰图火焰图清楚地显示事务已经启动，但在其余部分，没有Commit或Rollback操作。这肯定是一个操作问题。那么也很清楚问题出在：MainController.update方法内部，废话少说，直接去update方法查看。找到以下代码：func(c*MainController)update()(flagbool){o:=orm.NewOrm()o.Using("default")o.Begin()nilMap:=getMapNil()ifnilMap==nil{//这里只检查是否为nil，不执行回滚或commitreturnfalse}nilMap[10]=1nilMap[20]=2ifnilMap==nil&&len(nilMap)==0{o.回滚()返回false}sql:="updatetb_usersetname=%swhereid=%d"res,err:=o.Raw(sql,"Bug",2).Exec()iferr==nil{num,_:=res.RowsAffected()fmt.Println("mysqlrowaffectednums:",num)o.Commit()returntrue}o.Rollback()returnfalse}至此所有分析结束。查看getMapNil后返回nil，但是后面的判断条件没有回滚。ifnilMap==nil{o.Rollback()//这里回滚returnfalse}综上所述，整个分析过程还是浪费了很多时间。最主要的是主观意识太强了。为什么跑了一年感觉没问题？所以一开始，SRE、DBA、各种基础设施都有问题（人总是先怀疑别人）。这花了很多时间。想想正确的分析思路：出现问题后，应该马上查看日志，确实在日志中没有发现问题；监控明显是socket在增长，很明显应该马上用netstat查看情况，看看是哪个进程引起的；根据netstat检查，使用tcpdump抓包分析连接被动断开的原因（TCP知识很重要）；熟悉代码的直接查看业务代码，不熟悉的可以使用perf打印出代码的调用链接；无论是分析代码还是火焰图，应该都能快速定位问题。那么这次为什么会出现CLOSE_WAIR呢？大部分同学应该都明白了，这里简单说明一下：因为那行代码没有回滚事务，所以服务端没有主动发起关闭。因此MySQL负载均衡器在到达60s时主动触发close操作，但是通过tcp抓包发现服务器没有响应。这是因为代码中的事务没有被处理，导致大量的端口和连接资源被阻塞。占据。挥手时贴出抓包数据：#mysql主动断开连接11:38:45.693382IP172.18.0.3.3306>172.18.0.5.38822:Flags[F.],seq123,ack144,win227,options[nop,nop,TSval3000355ecr2997359],length0#MySQL负载均衡器发送fin包给我11:38:45.740958IP172.18.0.5.38822>172.18.0.3.3306:Flags[.],ack124,win229,options[nop,nop,TSval3000360ecr3000355],length0#回复ack希望这篇文章能帮助大家排查线上问题。为了帮助大家理解，下面附上正确情况下的火焰图和错误情况下的火焰图。大家可以自己比较。Theflamegraphinthecorrectcase错误情况下的火焰图我参考了一篇文章，针对这种情况提出了两个思考题。我觉得很有意义。大家自己想一想：为什么一台机器上几百个CLOSE_WAIR会导致失败？继续参观？我们不是常说一台机器有65535个文件描述符可用吗？为什么我有负载均衡，但是部署服务的两台机器几乎同时出现了CLOSE_WAIR？参考文章：又见CLOSE_WAITTCP4次关闭个人公众号：dayuTalk
