写在前面的话
应某位友人需求,帮整理下工作中的发生的一些值得记录的文章。于是在友人描述后,为其整理为了文章,供大家一起参考探讨。
问题描述
在我们中应用有一个使用到`Http Long Poll`的场景,它需要一个http请求保持最长30秒,用于即使获取到最新的数据。在k8s环境下,发现应该存在偶发的异常,表现为长连接没有正常关闭,抛出异常:
java.net.SocketException: Unexpected end of file from server
问题排查
- 应用异常排查
首先我们先对应用程序的代码进行了排查,并没有发现代码上的bug,可以排除是由于代码bug导致的这个问题。
- 抓包
接下来考虑的方式就是抓包,分别在三个节点上进行抓包:应用程序所在pod、ingress-nginx所在pod、服务端pod。
分别执行以下shell脚本:
tcpdump tcp -s 0 -w ./target.cap
抓取当前网卡下的所有tcp流量,然后使用wireshark进行分析。发现了一个比较奇怪的现象:
从上到下三张图片分别是应用程序端、nginx端、服务端的抓包数据,可以发现连接的关闭是由nginx这个节点发起的,应用端和服务端同时收到了来自nginx的FIN ACK包,要求关闭当前连接,并且都开始执行四次握手过程。但是在这个过程中又发生了什么异常导致这个过程并没有正常完成。
通过观察大量的抓包数据后发现这个情况发生的非常多,但并不是每次都会导致连接的异常关闭,大部分还是能够正常关闭连接并建立新的连接的。
通过仔细观察发现被异常关闭的连接,都是发生在Seq=1的情况下,这个原因还不是很清楚。
那为什么nginx会主动发起关闭连接呢?
Nginx 排查
这时候首先想到的就是nginx的日志,在翻查了nginx的access.log后,发现在相同的时间段,nginx都发生了reload现象:
backend reload requiredingress 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的连接会发生这个异常,还是没有完全想明白。
#职场众生相##职场达人说##我要上头条#