很久没有分析一个生产问题超过3天了，是TCP的一个血案，C语言编写。我是一个Java人员，这次只能依靠对TCP三次握手，四次断链的理解，结合网络抓包和系统收集信息来对问题进行分析，过程虽然烧脑，但当完成定位后，还是比较兴奋。对TCP的理解，更精进了一步。整个事件，从疑惑到全部理顺，感觉知识是相通的，编码是工具，认知很重要。闲来之余，特此记录一下整个分析。系统是一个自助设备机具和服务端MC进行通讯的一个过程，可以看做C/S的TCP通讯架构，短连接，连续2天生产凌晨3点左右出现服务响应超时的问题。

      4月18日第一天：生产监控反馈凌晨3点左右，系统交易超时，交易没有应答，项目组MC的开发人员初步结论：1、在异常时间，服务端系统在accpet阶段，C函数返回大量72的错误，不知道是啥，是系统函数抛出的。2、一天前，分析一笔交易超时，结合端机发送时间和服务端的时间，可以看到报文在发出几分钟后，才接到这笔报文进行处理，报文处理时间秒级很快。

        有限的信息真的是懵，服务端一直没有变动过，是C语言的系统，要是Java肯定很容易看，负责服务端MC的同事一直说程序没有变动，客户端有很多种机具，没法进一步跟进。此刻只能和项目组一起开始抽丝剥茧，一步一步引导分析(系统变更都说没啥重要的)：

      a) 为什么系统函数accept在接收报72；问度娘，注意是AIX的72系统错误，不要查Linux的72系统错误，度娘说该错误被描述为“software caused connection abort”，即“软件引起的连接中止”。原因在于当服务和客户进程在完成用于 TCP 连接的“三次握手”后，客户 TCP 却发送了一个 RST （复位）分节，在服务进程看来，就在该连接已由 TCP 排队，等着服务进程调用 accept 的时候 RST 却到达了。POSIX 规定此时的 errno 值必须 ECONNABORTED。

      啥叫软件引起的连接，写了这么久程序，也没有碰到过accept的系统错误，问了以前的C语言同事，一般通过主进程接收accept形成socket句柄对象后，会fork出一个子进程接管这个socket进行业务处理，没有碰到过。软件引起的连接中止，这个怎么解读，没有人知道，难道系统在那个时间段做了啥，可是现场没有任何数据啊，难道有后台任务在执行，导致系统问题？

      b)为啥会接收报文缓慢，机端短连接，客户端90秒就断开连接了，按照Java开发，只要建立链路后recv，客户端发送数据，接收数据应该很快，但是日志显示确实是2分钟后接收到，又是一个见鬼的问题，Java开发不会碰到，除非服务端处理程序问题，查看C程序在fork出子进程，子进程的第一步就是recv接收数据，在接手前没有任何处理，所以应该不会慢的，难道当时系统对recv也有影响？ 带着这些疑问，开始几步走：

      第一步让运维人员确定3点左右系统的负载，是否后台的定时任务，服务器是否有变动，得到的结论后台定时任务不会有影响，系统当时的负载正常，前几天做过一些主备机切换演练。

      第二步：请运维人员提供凌晨2:30-3:30之间的网络包进行分析，不得不佩服网络是个专业的领域，当天的网络包基本旁路备份好的，只是提取确实麻烦点，呵呵。我们希望看看当时的通讯情况，这个时候需要考验大家对网络包的理解能力，要充分理解三次握手，四次挥手的原理，否则看网络包会比较吃力。下面几张图：

    客户端发送数据后，进行单边断链，但是网络仍然能收到Keep Alive的心跳包，理论上服务端应该很快进行断链响应，但是服务端一直没有返回断开，这也说明了，链路建立了，但是就是没有对数据进行处理（排除业务处理慢，已经证实），没有断开。途中白色是服务端端口。

下图显示，客户端建立链路5分钟后，服务端仍然没有处理，客户端发起了主动的RST中断连。

  第三步，开始引导阅读C语言的代码，看看主进程Listener的处理，进行accept生成socket对象进行fork子进程，接管这个socket进行handle_message对象处理。重点关注accpet的一段逻辑，当fork出的子进程超过200的时候，他会循环休息1秒。直到有子进程处理退出。子进程在处理socket信息的时候，先进行recv，然后进行业务处理，然后发送UDP数据包给另外一个模块进行统计。如果这个子进程处理完毕，可以当前子进程accept新的线程进行下一个应用包的处理，当子进程的运行时间超过15分钟或者处理超过指定交易笔数会自动退出。

    注意C语言的通讯真是牛，可以写成多个子进程在同一端口，通过accept进行连接获取，然后进行业务包的获取，也不像Netty，Tomcat等中间件的通讯设计，由一个Rector的群组线程池专门负责建立链路，进行selector的注册侦听，由专门的工作线程池对业务进行处理。这个C程序被写成子进程fork出后，可以同一个端口accept接收建立链路，然后自己处理。确实是思维上有点冲击。

  4月19日第二天：由于18日的信息太少，只能知道凌晨三点机端的响应率低，向运维提出记录凌晨2:30-3:30每隔分钟收集进程，端口的使用信息，包括利用tcpdump在本机收集网络信息，具体的收集指令 tcpdump  tcp -i eth1 -s 0 port  10000 -w ./target.cap， netstat -an >a.txt  ps -ef >b.txt等。事情如预期，在凌晨3:00左右继续出现了响应率低的问题。获取信息进一步分析：

第一步：查看网络端口信息，在10000端口上建立的链路确实一直没有变动，也没有销毁，存活时间基本都在30-50分钟内，其中断开链路，应该是F5的长连接的空闲超时设置，F5进行的断链请求。需要通过F5节点的网络包看看那些长连接处于空闲状态，主动断开，通过网络定位了一批机器IP。基本属于自助设备，自助设备一般会在凌晨不同时间段重启，所以交易白天基本没有遇到。

第二步：查看进程，发现这个时候MC的子进程已经到200个，系统的最大进程已到，但是日志显示这些子进程全部都没有工作，只有1个子进程看到了应用报文的处理，其它似乎都被Hang住了，结合第一天的分析，子进程在accept->recv->handl_message->close然后周而复始，排除handl_message的业务堵塞（虽然有统计，但是通过UDP发另外一个进程处理），根据TCP的原理只有可能发生recv的时候，查看代码可以看到原程序在recv是没有设置超时时间。

第三步：信息差不多了，通过网络F5层的包恢复，通过wirkshark包分析工具，抽取到的IP为自助设备，不是ATM，VTM等远程设备。提取端机日志，基本那个时候端机重启，重启后就发生了问题。问题集中点已经 定位，原来3月版本为了更好的对自助设备的交易链路做可用性检测，错误的时候给到准确信息。自助机器重启后，机端对链路做端口可用性检测，在底层框架选择telnet 命令进行端口探测，却没有进行关闭，导致telnet通了后，服务端一直接收不到数据包，最终服务端子进程被hang住，只能被动的等待F5的30分钟的断链请求。一般F5也有链路可用性探测包，有些应用程序没有处理好，导致程序异常。

    至此，这个问题的原因基本定位，一是修改机端程序，主动关闭2socket；而是修改服务端程序，增加recv的超时设置，可惜的是C语言的socket超时，不像Java在socket中设置ReadTimeOut方便，需要在古老的程序中加入signal，alarm的信号量方式来进行控制。阿弥陀佛，改的时候小心谨慎，多双眼睛，生怕搞错（呵呵）。

    4月20日第三天：由于修改服务端程序需要测试，而机端修改不可能，一夜之间无法分发所有的机器（这个是下下策），所以凌晨0:00调整了F5的超时时间从30分钟到5分钟，这样避免问题的影响时间。服务端的recv超时设置也在随后上线，彻底解决了此问题。

      问题算彻底定位解决了，但是在整个处理过程中，仍然留下了一些疑惑没有解决，需要我们继续去从原理上说服自己，让自己还原真相：

    问题一：为什么服务端在出现问题的时候，会有72的错误码？官方72错误被描述为“software caused connection abort”。我突然理解这个软连接中断应该是说，服务端在进行accept的时候，连接已经被客户端主动提前RST复位了，导致了accept的72系统错误。我们看看TCP的三次握手：

    　半连接状态为：服务器处于Listen状态时收到客户端SYN报文时放入半连接队列中，即SYN queue（服务器端口状态为：SYN_RCVD）。

      全连接状态为：TCP的连接状态从服务器（SYN+ACK）响应客户端后，到客户端的ACK报文到达服务器之前，则一直保留在半连接状态中；当服务器接收到客户端的ACK报文后，该条目将从半连接队列搬到全连接队列尾部，即 accept queue （服务器端口状态为：ESTABLISHED）

    从途中可以看到，在accept之前，在第三次握手的时候网络上已经完成了正常的链路建立，在客户端和服务端可以看到ESTABLISHED状态，所以客户端可以发送数据，在C语言中，accept之前链路居然可以已经建立了，但是在Java语言的客户端连接，必须等服务器accept后这个链路才能建立成功，客户端的connect方法才能返回成功，继而发送数据，这是和C语言通讯完全不一致的地方。由于服务端的所有进程都被Hang住，或者处理较慢，机端在发送数据后得不到响应，超时或者系统发送RST复位。为什么得不到响应呢，在前面分析的时候可以看到，如果主进程判断整个进程数200的时候，一直会循环等待，进程数少于200，才会从accept queue取一条连接。这个时候，从accept queue取出一个连接可能由于时间过长，是不可用使用的，系统就会出现72个错误。自此，我们可以基本解释为什么系统在出现问题的时候，日志上出现了72的错误。其实框架的整个设计已经让accept queue在系统达到峰值后，就不会及时进行处理的，这个Netty的NIO处理机制完全不一致。

      问题二：为什么报文会在几分钟后处理。如果放在Java应用中，我一般认为是业务处理线程过慢导致的，但是本次问题，我们可以看到在接收数据后，业务处理都是毫秒级就完成了，唯一的解释就是Recv读取数据或者Accept的时候慢了，通过前面的分析，我们可以基本断定是链路在ESTABLISHED状态的时候，客户端发送了数据，但是服务端子进程在从accept queue中取连接已经慢了，要等服务telnet的子进程被F5超时后，才有可能有新的子进程accept 连接，这个时候读取到应用报文，然后进行处理。所以我们可以看到问题发生的时刻端，有报文出现客户端和服务端的时间差几分钟。由于连接断开是双方的，客户端虽然断开了，但是在链路中的数据，服务端仍然可以获取该数据。这个是由TCP的四次挥手机制决定的。

  问题三：网络抓包显示，客户端发送了FIN包断链请求后，心跳包Keep Alive仍然能发送。一般情况下，在断链一方发送FIN包后，后续的应用发送的数据都会报错，链路应该是一件断开了。但是从网络抓包看，对于类似探链路TCP的KeepAlive机制的数据包，确实会可以继续。查阅资料显示心跳机制不属于标准的TCP规范，试验确实也发送了，找了专家也没有答案，只能记着这个现象吧，对应用确实没有影响。

      当一个 TCP 连接建立之后，启用 TCP Keepalive 的一端便会启动一个计时器，当这个计时器数值到达 0 之后（也就是经过tcp_keep-alive_time时间后，个 TCP 探测包便会被发出。这个 TCP 探测包是纯 ACK 包。默认情况keepalive机制受三个参数控制。1、tcp_keepalive_time，最后一次数据交换到TCP发送第一个保活探测包的间隔，即每次正常发送心跳的周期，默认值为7200s，2、 tcp_keepalive_probes 在tcp_keepalive_time之后，没有接收到对方确认，继续发送保活探测包次数，默认值为9（次），3.  tcp_keepalive_intvl，在tcp_keepalive_time之后，没有接收到对方确认，继续发送保活探测包的发送频率，默认值为75s。

      一般的应用通讯程序，不建议使用keepAlive机制去探测链路是否可用使用，因为KeepAlive机制的参数受操作系统控制，在机端的发送程序，是对心跳机制的发送周期做了修改，每2秒发送一次，所以在网络抓包分析中看到了心跳包大概是2秒一次。我们熟悉的dubbo分布式，就是在应用层做心跳包判断zk和服务器之间的连接检查。

      至此，一个跨系统网络问题分析也尘埃落地，一个依靠TCP原理，Java开发经验进行分析的过程结束了。再一次证明很多东西是相通的，认知很重要，我们需要发挥工匠精神，做到知其然知其所以然，让所有的现象合理化。这次TCP惨案重点解析了3次握手的建立链路过程，日常我们还会碰到许多连接关闭的问题。大量的close wait为什么有？Http1.1到底是怎么进行链路断开的呢？一切皆有因果，纸上得来终觉浅，绝知此事要躬行，不放弃任何一个问题，不放弃任何一个成长的机会，再见！