HTTP零窗口事件

kiwi__
421 阅读8分钟

现象

设备通过http接口下载文件，下载失败。

客户设备在自己搭载的环境下载不成功，下载进度到26%左右就失败

测试侧可以概率性复现出此场景。

  • 部分设备会出现问题
  • 小固件不会出现问题

注：下载文件的逻辑是从本地文件读取，通过文件流传输出去，很简单的代码。

定位问题

在日志上寻找出相关错误信息

image.png

从日志上可以看出，堆栈跟踪抛出了java.net.SocketTimeout异常，通过对异常信息的字面理解，可以看出是连接超时导致的异常。

根据堆栈信息可以看出其是在做writeBytes 时出现的超时异常，出现了写入超时。 定位接口以及相关方法

https://xxx/storage/download?id=a115a0b4fd3e4dd0b2983ee616f8c4be

通过浏览器直接访问即可下载，由此判断接口无问题。

在单独定位接口无误后，可以判断出现 超时（SocketTimeoutException） 的场景只能和 设备交互的环境中排查。

但是具体为什么会出现写超时的场景，回忆以往处理的bug经历，应该没遇到过。

由于这个属于这次的版本才出现的bug，需要先验证下别人是否有修改过相关的代码，毕竟此问题一看就不是个几个小时内能排查出来的bug。

  • 查找相关代码历史修改记录：没内容

  • 询问同事：询问了测试以及同事有没有相关的问题/技术支持。并没有。

由于此问题比较难见，并且能提供的相关信息较少，即使把单纯的报错去网上查找个半天啥也查不到。

目前来看只能通过抓包复现问题

抓包复现

通过和设备的测试同事千辛万苦复现出了错误场景，并且导出了出现此问题的时间段抓出的包。

image.png

分析包

注：

  • HTTP请求后，两台计算机交互的request和response，会由TCP操作。其信息传递会比单纯的传递request和response要复杂。通过TCP建立的通讯往往需要计算机之间多次的交换信息才能完成一次request或response。
  • RST：RST表示复位，TCP中用来异常的关闭连接。发送RST包关闭连接时，不需要等缓冲区的包都发出去（不像FIN包），直接就丢弃缓存区的包发送RST包。而接收端收到RST包后，也不必发送ACK包来确认。

所以如抓包的上图所示，在服务端传输固件数据给终端时：是不正常的接收，返回消息。而是到处出现TCP window full信息

以及最终能看到服务端（10.200.110.51)下发了 RST。

image.png

从这里看出来，是服务端导致出了一些问题，由我们服务端主动关闭链路。

通过对整个包分析，又看到了另一个奇怪的内容

image.png

可以看出终端在我们固件下载一半后，主动向我们发了一堆rst。

同时服务端日志中打印了

image.png

从这里看出来，上图可以看出设备主动关闭了连接。此问题是来源于设备：为何会主动关闭链路？

不过在目前看来，这是一个新的报错，

1.出问题的是jav.net.SocketTimeoutException：连接超时

2.此次报错是IOException:Brokenpipe：主动断开

分析相关的资料

此次需要捋清几个问题

  • 设备下载固件的逻辑（排查的优先级最高）

通过和设备几个逻辑层的开发讨论后，得到的结论：

部分设备机型（除了现在现在较新的）因为硬件内存限制的原因，会边安装边下载。

在下载包的时候，如果是在检测到不是可以升级的版本等问题会断开下载。

  • 什么样的场景会出现TCP window full/zero window（抓包中出现的问题）

网上资料中：

TCP window full, 是指的发送端发送的数据已经达到的接受窗口的上限。 继而停止发送,等待新的接收窗口的通告。

TCP中获得Zero窗口的原因是因为接收器的recv缓冲区没有空间。 有很多种方法可以实现。此问题的一个常见原因是当您通过LAN或其他相对较快的网络连接发送时，一台计算机明显快于另一台计算机。作为一个极端的例子，假设你有一台3Ghz计算机通过千兆以太网尽快发送到运行1Ghz cpu的另一台机器。由于发送方的发送速度比接收方能够读取的速度快得多，因此接收方的recv缓冲区将填满，导致TCP堆栈向发送方通告零窗口

ZeroWindow, 当发送方的发送速度大于接收方的处理速度，接收方的缓冲塞满后，就会告诉发送方当前窗口size=0，请停止发送，发送方此时停止发送数据。

结论

最终总结出的结论是：服务器的发送速度 快于终端 收的速度

对于经验而言，根据个人经验，控制服务器 request/response 速率的地方有主要几处：

  • nginx：如配置缓存区大小，配置传输速度等

  • 带宽：TCP拥塞协议，滑动窗口会根据当前带宽，动态控制窗口的大小

  • TCP缓冲区大小：服务器可以设置默认socket缓冲区大小

解决

排查nginx，询问运维是否修改过配置

通过层层过滤查找/询问历史修改记录，这里得知此次版本新加上了这几个配置。


proxy_buffering off;

proxy_buffer_size 128k;

proxy_buffers 100 128k;

所以找到了这次出问题的根因，proxy_buffering被关闭了，tomcat线程发送的信息不会通过nginx的缓冲区转发，而是直接秒传给终端。

让测试去除这些参数后已经不会再出现。

终端为什么会发RST /服务端日志打印的IOException:Brokenpipe异常含义 （抓包中出现的问题）

由设备下载固件的逻辑，回归日志寻找设备当时下载的文件，发现版本不匹配，所以下载了一半断开了连接。

IOException:Brokenpipe

某个客户端突然中止了进程导致了该错误

终端断开了连接，所以打印了该异常

服务端为什么会发RST/服务端日志jav.net.SocketTimeoutException异常含义 （此次问题异常的问题）

剩下最后一个问题，虽然根据TCP window full 已经定位出问题所在了。但是并没有定位出服务器异常的真正问题

jav.net.SocketTimeoutException在网页上查询的资料很少（StackOverflow，百度等），基本出问题的不在服务端，都在客户端调用http请求时才出现。

image.png

通过网上资料查询找不到时，阅读源码才是最有效的方法

阅读源码

回到日志输出错误的堆栈

image.png

image.png 可以看到虽然出现了ClientAbortException，但是并没有抛出我们要的SocketTimeoutException异常。

证明异常在doWrite里面抛出。

image.png

进入doWrite后，发现他有几百个实现，并且实现里面还有很多个接口。很难找到具体是在那个类具体实现。

用debug的方式，一层一层进去看，或者可以直接在异常上面打断点找到上级调用。

最后找到是这个实现类。

image.png 通过最后的解读，可以看到其异常是由writeTimeout控制的 image.png

其值的引用和赋值便是： image.png

我们配置的connect-timeout便是这个writeTimeout的值。

从上放的源码中可以得出，我们Tomcat线程和设备8秒未进行通信（或者什么场景），主动关闭了链路（发送RST），抛出了SocketTimeoutException。

回到抓包中的场景，TCP window full/zero window。

分析相关资料：

TCP坚持定时器（blog.csdn.net/zhuaimiao1/…）

当零窗口出现后，如何继续数据的传输呢。

假设：接收方窗口更新为非0后，发送ACK给发送方，更新window的size，是一种可行的方式。

但是如果这个ACK丢掉了（TCP不会给ACK回复ACK），那么发送方和接收方就会处于一种尴尬的局面，一个等着发，一个等着收，直到超时。


此时TCP中加入了坚持定时器的概念，由发送方主动创建，持续不断地询问接收方窗口是否更新，这个询问被称为窗口探测（window probes）。


坚持状态与重传超时之间一个不同的特点就是TCP从不放弃发送窗口探查。


这些探查每隔60秒发送一次，这个过程将持续到窗口打开或者应用进程使用的连接被终止。

所以这个问题中，TCP坚持定时器没有时间限制，意味着这个TCP连接会永远保持下去。

但是对于tomcat中，创建的其长连接，无根据坚持定时器的逻辑 ，只是根据connectionTime的设置值，而关闭了链路。

模拟异常场景

编写代码，使用socket的方式，开启keepalive 下载http请求，并且在读取文件流的时候休眠

public static void main(String[] args)
          throws Exception {
      String destLoc = "E:/test";
​
      InetAddress addr = InetAddress.getByName("10.200.110.171");
      String ip = addr.getHostAddress();
      int bias = 0;
      String encoding = "utf-8";
      Socket socket = new Socket(ip, 9989);
      InputStream is = socket.getInputStream();
      OutputStream os = socket.getOutputStream();
      BufferedWriter writer = new BufferedWriter(new OutputStreamWriter(os, encoding));
      writer = new BufferedWriter(new OutputStreamWriter(os, encoding));
      writer.write("GET " + "/storage/download?id=b4f34e4119c9dcc7e19e3de48ad" + " HTTP/1.1\r\n");
      writer.write("Host: " + "10.110.110.110" + "\r\n");
      writer.write("Connection: keep-alive\r\n");
      writer.write("\r\n");
      writer.flush();
​
      is.skip(bias+2);
      String fname = "123";
      FileOutputStream fos = new FileOutputStream(destLoc + fname );
      byte[] buf = new byte[1024];
      int len;
      while((len=is.read(buf)) != -1) {
​
          Thread.sleep(1000000000);
          fos.write(buf, 0, len);
      }
      fos.close();
  }

复现：

image.png

所以得到结论：

Tomcat对 TCP坚持定时器没有做处理逻辑，只根据自身的connectionTimout决定是否关闭链路。

avatar
文章
阅读
粉丝