宝塔服务器面板，一键全能部署及管理，送你10850元礼包，点我领取

对于云用户来说，在业务日志中报告超时的问题有：1)问题可能在云基础架构层，也可能在业务软件层，因此需要进行故障排除的范围非常广；2 )这种问题是不可再现的问题本文分析了如何识别和排除这类问题的根本原因。

根据

业务超时 != 网络丢包

业务形态的不同、软件的实现语言和框架的不同，业务日志中打印的信息可能各不相同。 例如，以下关键字。

‘ SocketTimeOut ‘、’ Read timed out ‘、’ Request timeout ‘等

虽然在形式上均属于网络超时一类，但这种问题是由于请求超过了设置的timeout时间，该设置可能来自客户端、服务器端或网络中间节点，这是直接原因网络丢包可能会超时，但这不是足够的条件。 总结一下业务超时与网络丢包的关系，结果如下：

网络丢包可能会导致业务超时，但业务超时的原因不一定是丢包。

在明确了这个因果关系之后，让我们来看看如何分析业务超时。 如果武断地将业务超时设置为与网络抖动的丢包相同，则该故障诊断分析过程会完全漏掉业务软件层自身的原因，容易进入困局。

本文从云基础架构层和业务软件层分析业务超时。 总体而言，基础架构层丢包原因比较容易调查，Alibaba云(AlibabaCloud )有完善的基础监控，根据业务日志错误报告的对应时间段，根据监控数据判断是否存在基础架构网络问题业务层超时通常是软件级别的设置，关系到软件的实现和业务形态，这往往更难排除。

网络丢包为什么导致业务超时

网络抖动可能导致业务超时，其主要原因是网络抖动造成不同程度的延迟。 本文以互联网大部分应用以来的TCP为对象进行介绍。 丢包其实并不影响数据传输的完整性。 这是因为TCP协议本身已经被精密设计用于处理丢包、顺序混乱等异常。 所有重发的处理都是在内核TCP协议栈上进行的，而操作系统的用户空间进程实际上不知道该处理。 丢包的唯一副作用是延迟的增加，如果这个延迟足够长，并且应用进程达到了设定的时间超时时间，业务APP应用程序端出现的就是业务超时。

发生丢包时是否发生超时取决于应用进程的Timeout设置。 例如，在数据传输中的TCP分组仅丢失了一个，引起了200 ms后的超时重发的情况下：

如果APP应用程序设置的Timeout为100 ms，并且TCP协议栈没有机会重新发送，则APP应用程序将视为超时并关闭连接。 如果应用设置的Timeout为500 ms，则TCP协议栈将完成重传并对应用进程透明地处理。 唯一的感知是将这次消息交互处理得比基线处理长200 ms，对于时间灵敏度不是很高的APP应用来说这种影响非常小。

延迟到底有多大？

设置应用进程Timeout时间时有没有可以参考的定量值？ TCP中RTT/RTO都是动态变化的，但TCP丢包发生的影响可以有一定的定量总结。

丢包导致的延迟主要有以下两种。

TCP建联超时。 如果网络抖动导致TCP的第一个内部版本SYN消息丢失，则客户端将在一秒钟(由Draft RFC 2988bis-02定义)后重新发送SYN消息并重新开始内部版本。 1秒对于内部网环境来说非常大，对于在一个区域内运行AlibabaCloud (阿里巴巴云)的机房来说，正常的RTT都是小1位数的毫秒级，1秒内如果没有丢包，就足够完成100个数据报的交换TCP中间数据包的丢包。 TCP协议处理中间数据分组丢失有快速重传和超时重传两种机制。 快速重传通常较快，与RTT相关，无定量值。 虽然超时重传(RTO，Retrasmission Timeout )也与RTT相关，但是Linux中定义的RTO的最小值为TCP_RTO_MIN=200ms。 因此，在RTT比较小的网络环境中，即使RTT小于1ms，TCP超时重发的RTO的最小值也仅为200ms。 这种丢包导致的延迟比较小。 除丢包以外的一个常见延迟是TCP Delayed ACK引起的延迟。 这与协议设计有关，虽然与丢包实际上没有关系，但是在这里总结延迟定量这样的部分。 在交互式数据流Nagle算法的场景中很容易触发。 在Linux上定义的延迟ack的最小值TCP_DELACK_MIN为40 ms。

归纳起来，以下定量时间可供参考。

40毫秒，在交互式数据流中打开了TCP Delayed ACK Nagle算法的场景，最小延迟值。 在200 ms、RTT比较小的通常的网络环境中，TCP分组的丢包、超时重发的最小值。 1 s，RFC2988bis中定义的initialrtovaluetcp _ time out _ init。 内核版本TCP中建立的第一个SYN分组丢失分组时的重发时间。 3 s，由旧内核版本的TCP建立的第一个SYN数据包丢包时的重发时间。 RFC 1122中定义的initialrtovaluetcp _ time out _ init。

云基础设施网络丢包

基础设施网络丢包的原因可能有多种，主要分为以下三类：

云基础架构的网络抖动

存在网络链路、物理网络设备、ECS/RDS等的瘦主机虚拟化网络都可能出现硬件和软件问题。 云基础架构是完全冗馀的，以便在出现问题时能够快速隔离、切换和恢复。

由于现象：具有网络冗馀设备并且可以快速恢复，因此这种问题通常表现为一个单点网络抖动，通常为秒级。 抖动的具体现象

是在那个时段新建连接失败，已建立的连接中断，在业务上可能表现为超时。

影响面: 网络设备下通常挂很多主机，通常影响面比较大，比如同时影响多个ECS到RDS的连接。

云产品的限速丢包

很多网络云产品在售卖的时候有规格和带宽选项，比如ECS, SLB, NAT网关等。当云产品的流量或者连接数超过规格或者带宽限制时，也会出现丢包。这种丢包并非云厂商的故障，而是实际业务流量规模和选择云产品规格时的偏差所带来。这种问题通常从云产品提供的监控中就能分辨出来。

现象: 当流量或者连接数超过规格时，出现流量或者连接丢弃。问题可能间断并持续地出现，网络流量高峰期出现的概率更大。

影响面: 通常只影响单一实例。但对于NAT网关做SNAT的场景，可能影响SNAT后的多个实例。

运营商网络问题

在走公网的场景中，客户端和服务器之间的报文交互往往要经过多个AS (autonomous system)。若运营商中间链路出现问题往往会导致端到端丢包。

现象: 用双向mtr可以看到在链路中间某跳开始丢包。

影响面: 影响面可能较大，可能影响经过某AS链路的报文交互。但是对于单用户来说看到的影响通常只是对特定实例。

应用设置的Timeout引发的超时

上面分析了几种基础设施因为异常或限速等原因丢包导致应用超时的情况，总体来说只要能找出丢包点，就基本能找出根因。但有些情况下，各种网络监控表明并没有任何丢包迹象，这个时候就要从应用侧面来继续排查下了。因为应用的形态多样，下面以两个典型例子来说明为什么在没有网络丢包的情况下也会出现业务日志中的超时。

ECS云主机访问第三方API超时的例子

问题现象

用户云上ECS服务器需要通过HTTP协议访问第三方服务器的API，但是发现业务日志中时不时出现访问第三方API时的”Request timeout”报错，需要查出根因。

排查思路

根据基本思路，先从监控中查看ECS实例及链路有没有丢包。结果发现并没有能和业务日志中出现timeout报错时间点吻合的丢包。在这种情况下，只能进一步利用问题复现时的抓包来一探究竟了。

抓包分析

拿到抓包后，可以通过Wireshark的“分析-专家信息”或者如下表达式来过滤是否有重传。

tcp.analysis.retransmission

结果确实没有看到任何一个丢包，这个也反证了该问题并非由丢包引起。如果不是丢包引起，那为什么会产生问题呢？这时候需要进一步来分析抓包。

我们可以注意到：在业务日志里其实有”Request Timeout”这样的关键字，从字面理解就是往外的HTTP请求超时。用HTTP协议的话来说，可以翻译成：“HTTP请求已经发给对端，但是在一段时间内对端并没有返回完整的响应”。沿着这个思路，我们可以看下报文里是否存在只有HTTP请求而没有HTTP响应的情况。在Wireshark里，可以用如下方法过滤没有HTTP响应的HTTP请求：

http.request.method == GET && !http.response_in

果然，我们发现了一些这样的HTTP请求。选择其中的一个HTTP请求，然后跟一下TCP stream看下报文交互的全过程如下：

根据抓包会有如下一些发现：

TCP stream中可以看到一个TCP连接上有2个HTTP请求，所以ECS访问第三方API是用的长连接。第一次HTTP GET请求(735号包)，在65 ms后返回(778号包)。第二次HTTP GET请求(780号包)没有对应的HTTP响应返回 (我们正是通过这个条件过滤的报文)。第954号包，客户端没等收到HTTP响应就主动FIN掉了TCP连接。这是个很异常的行为，并且是客户端发起的。仔细观察FIN和第二个HTTP GET请求发出的时间间隔，发现大约300 ms。接着查看其他没有响应的HTTP stream，这个时间间隔大约300 ms。

至此我们有理由推断是ECS服务器在对第三方API发出HTTP请求300 ms后主动FIN掉了TCP连接。这可能是程序中客户端设置的超时时间，业务程序超时后可能有自己的重试逻辑。

用户最后确认了业务软件中有该超时设置。

问题总结

1) 那这个300 ms的超时时间设置是否合理呢？

从抓包中可以看出，ECS对端API服务器的RTT大约7 ms左右，推断是一个同城的访问。对于个位数毫秒级别的RTT，300 ms的超时时间其实已经有一定余量了，并且甚至可能可以允许一次超时重传(200 ms)。

2) 问题的根因？

该问题主要是由于对端API服务器处理请求的速度不稳定造成。有些请求在几十毫秒内就处理返回完，有些300 ms都没有处理完。这个不稳定可能和API服务器的资源水位和压力相关，但是这个是黑盒，需要对端分析了。

3) 解决方案

1> 最佳解决方案是联系对端API服务器的owner找到根因并根除。

2> 临时解决方案是调整增大ECS上设置的客户端超时时间。

ECS内网访问自建Redis超时的例子

ECS访问云服务RDS/Cache或者自建数据库/Cache超时是另外一类问题，下面用一个ECS内网访问字节Redis超时来说明这类问题。

问题现象

ECS上用Redis客户端Jedis访问自建在ECS上的Redis服务器，偶尔会出现如下报错：

redis.clients.jedis.exceptions.JedisConnectionException: java.Net.SocketTimeoutException: Read timed out

排查思路

这类问题很常见的原因是Redis慢查询，用户自查了Redis的大key和慢查询情况，没有发现时间特别长的查询。所以需要在网络层面进一步确认。根据基本思路，先从监控中查看ECS实例及链路有没有丢包。结果发现并没有能和”Read timed out”报错时间点吻合的丢包。进一步利用问题复现时的抓包来一探究竟了。因为问题偶发，需要在客户端利用tcpdump -C -W参数部署循环抓包，问题出现后停止循环抓包来查看。

抓包分析

拿到抓包后，同样先看有没有丢包重传，结果是没有发现丢包重传。和上一个例子不同，这个例子没有办法通过一定特征来过滤数据包。所以只能根据Jedis日志报错的时间点找到对应包的位置来进一步看有没有什么线索。

根据Jedis日志报错的时间点找到对应的报文，跟TCP stream看下报文交互的全过程如下(Jedis客户端是9.20，Redis服务器端是20.66)：

根据抓包有如下一些发现：

可以看到中间没有重传，网络上看起来是正常的。客户端利用长连接访问服务器端，在结束连接之前已经包了非常多的Redis请求和响应。181073 号包是服务器端FIN掉了连接，181078号包客户端接着发了TCP Reset。

上面这些信息量显然是不够说明为什么有”Read timed out”的报错。最后一个从客户端发起的TCP Reset可能会是干扰项，可以看到这个TCP Reset是在收到服务器端的FIN而发出的。对于正常TCP四次回收结束连接的过程，客户端在收到服务器的FIN后应该也发送个FIN给服务器结束连接。但是TCP有个Linger选项，可以控制这个行为，设置了Linger选项后可以让客户端直接回Reset，这样可以让双方快速关闭这组socket, 避免主动关闭放进入长达60秒的TIME_WAIT状态。看起来是客户端的Linger设置造成的，搜了下Jedis代码，在Connection.java (如下)里果然有这个设置，这样就能结束为什么客户端Reset掉TCP连接，这个行为是符合逻辑的。

socket = new Socket();
socket.setReuseAddress(true);
socket.setKeepAlive(true); // Will monitor the TCP connection is valid
socket.setTcpNoDelay(true); // Socket buffer Whether closed, to ensure timely delivery of data
socket.setSoLinger(true, 0); // Control calls close () method, the underlying socket is closed immediately

接着来看报文交互中的Redis命令是否正常。跟踪TCP stream可以看到ASCII形式的数据，如下：

可以看到客户端发了DEL命令后，又发了QUIT命令，可以对照报文看下。

客户端在181061号包发出了DEL命令。在3.9 ms后收到了Redis服务器的ACK，注意这只是个ACK包，报文长度是0，说明没带任何payload数据。第181070号包，客户端又发出了QUIT命令，注意这个包和DEL命令的包相差间隔时间大概200 ms。Quit命令用于关闭与当前客户端与Redis服务器的连接，一旦所有等待中的回复(如果有的话)顺利写入到客户端，连接就会被关闭。第181072号包，也就是在QUIT命令发出161 ms后，Redis服务器端回复了”:1″和”+OK”。其中”:1″响应DEL命令，”+OK”响应QUIT命令。第181073号包，Redis用FIN报文结束了这个TCP长连接。

如上所述，这个连接被中断的关键点是客户端给Redis服务器发送了QUIT命令，至于为什么要发QUIT，并且是之前命令发出后200 ms没返回时发送QUIT，很有可能是有超时设置。查看另外几个TCP stream, 基本上都是以类似的模式结束了TCP长连接，基本上可以下这个结论了。

这个案例和第一个案例很类似，不同之点是在抓包里我们无法看到在超时时间过后客户端直接FIN掉连接，而是发了Redis QUIT命令，最终等到前面的命令执行完后才关闭连接。相比较第一种，这是一种更优雅的方法，前提是因为Redis存在QUIT命令，并且Jedis内化了这个操作。这个案例更清晰地说明了具体业务对连接行为的影响，需要利用报文来反推Redis客户端和服务器交互的行为。

总结

本文介绍了业务日志里面报超时问题处理起来需要考虑的两个层面：云基础设施层和业务软件层。有相当一部分的问题可能由于基础设施的网络丢包引起，通过网络监控和网络产品的云监控定位丢包点很重要，注意不要把业务超时等同于丢包；另一类业务软件层Timeout设置导致的超时，发生比例相对少，但需要更广泛的排查，并且不要轻易忽略了这类原因导致的超时。

作者：怀知