关于k8s下使用Ingress保持长连接的异常情况排查

发表于 更新于 分类于 阅读次数： 本文字数： 1.4k 阅读时长 ≈ 2 分钟

问题描述

1
在我们中应用有一个使用到`Http Long Poll`的场景，它需要一个http请求保持最长30秒，用于即使获取到最新的数据。在k8s环境下，发现应该存在偶发的异常，表现为长连接没有正常关闭，抛出异常：
1
java.net.SocketException: Unexpected end of file from server

问题排查

应用异常排查

首先我们先对应用程序的代码进行了排查，并没有发现代码上的bug，可以排除是由于代码bug导致的这个问题。

抓包

接下来考虑的方式就是抓包，分别在三个节点上进行抓包：应用程序所在pod、ingress-nginx所在pod、服务端pod。

分别执行以下shell脚本：

1
tcpdump tcp -s 0  -w ./target.cap

抓取当前网卡下的所有tcp流量，然后使用wireshark进行分析。发现了一个比较奇怪的现象：

client-tcpdump.png

nginx-tcpdump.png

server-tcpdump.png

从上到下三张图片分别是应用程序端、nginx端、服务端的抓包数据，可以发现连接的关闭是由nginx这个节点发起的，应用端和服务端同时收到了来自nginx的FIN ACK包，要求关闭当前连接，并且都开始执行四次握手过程。但是在这个过程中又发生了什么异常导致这个过程并没有正常完成。

通过观察大量的抓包数据后发现这个情况发生的非常多，但并不是每次都会导致连接的异常关闭，大部分还是能够正常关闭连接并建立新的连接的。

通过仔细观察发现被异常关闭的连接，都是发生在Seq=1的情况下，这个原因还不是很清楚。

那为什么nginx会主动发起关闭连接呢？

Nginx 排查

这时候首先想到的就是nginx的日志，在翻查了nginx的access.log后，发现在相同的时间端，nginx都发生了reload现象：

1
2
backend reload required
ingress backend successfully reloaded

难道是由于nginx的reload导致的问题吗？

通过查询发现，nginx reload的大致流程为：

  • reload命令触发nginx生成新的worker进程用于接受新的连接请求
  • old worker 进程不再接受请求
  • 对于仍然存在于old worker进程上的keep alive的连接，主动发送FIN ACK 包，通知对方关闭当前连接
  • 当所有old worker 上的连接都关闭或者超过worker-shutdown-timeout所设定的时间后，会关闭old worker 进程

通过查询k8s上ingress的默认配置发现， worker-shutdown-timeout被设置为了10s，这时候基本可以确定问题了，由于old worker关闭的窗口时间只有10s，如果在这个时间段内有连接还没有完成关闭，而此时old worker已经被关闭了，client端当然不能正常处理请求，因为它所连接的server端已经被提前关闭了。

解决

找到问题原因了当然接下来就是解决了，将 worker-shutdown-timeout该字段的值增大为：3600s，即1小时，理论上这个时间足够该worker上的连接全部完成关闭了。

在调整了k8s上ingress的这个参数后，又进行了反复测试，并没有再次发现同样的问题，该问题得到解决。

遗留

然后，为什么是Seq=1的连接会发生这个异常，还是没有完全想明白。