身在卷中不知卷
前言
懒怠的一个月,当然这说的是公众号文章输出,像是快一个月没有更了,当然工作是不可能倦怠的,卷的没法说~
抽个空更一篇近期碰到的工作问题,有关于防火墙空闲会话超时所引起的连接失败问题,问题虽然简单,但是故障原因和排查过程还是比较有趣的。
问题描述
某日研发中心容器同事反馈业务容器访问发生异常,偶发性报 connect timed out,又是这种疑似网络连接失败的问题,遂配合研发同事一起排查和处理,梳理业务系统故障相关信息后,说明如下:
-
故障现象是业务使用人员使用系统时,不定时偶发 connect timed out;
-
业务访问路径是从互联网 DMZ 区域至内网区域;
-
业务访问关系为:客户端容器 - F5负载均衡 - Nginx - 服务器。
网络拓扑如下:
虽然开篇明义说明了是防火墙相关问题,但是在整个排障过程中,实际会涉及到多方,并不是拿到某某数据包,就能一眼定位是哪哪的问题。像是上面拓扑所提到的环节,包括客户端应用、客户端容器、防火墙、F5负载均衡、Nginx、服务器,甚至说包括交换机方面,会涉及 6 个团队,问题出在哪方、引起问题的根因、数据包交互现象如何定位出故障等等,还需一一道来。
问题分析
阶段一
根据梳理的业务访问路径,因在互联网 DMZ 区域核心交换机上部署有流量镜像,所以通过科来 NPM 流量回溯分析设备调取了故障时间节点的前后数据包,数据包跟踪文件信息如下:
λ capinfos DMZ区域核心.pcapng
File name: DMZ区域核心.pcapng
File type: Wireshark/... - pcapng
File encapsulation: Ethernet
File timestamp precision: nanoseconds (9)
Packet size limit: file hdr: (not set)
Packet size limit: inferred: 70 bytes - 1518 bytes (range)
Number of packets: 20 k
File size: 9756 kB
Data size: 8904 kB
Capture duration: 1617.742436914 seconds
First packet time: 2023-03-10 16:12:48.238970749
Last packet time: 2023-03-10 16:39:45.981407663
Data byte rate: 5504 bytes/s
Data bit rate: 44 kbps
Average packet size: 437.37 bytes
Average packet rate: 12 packets/s
SHA256: b39edda2a04e109dd89dcfc89d82956a3036da3cca0cc6d912d8b18878584d5e
RIPEMD160: a7737a9aaf12786aa43b997ad1cd47c57acf01f2
SHA1: 42f2fec41eafb879942519985d47b22c64888c38
Strict time order: True
Capture application: Editcap (Wireshark) 4.0.4 (v4.0.4-0-gea14d468d9ca)
Capture comment: Sanitized by TraceWrangler v0.6.8 build 949
Number of interfaces in file: 1
Interface #0 info:
Encapsulation = Ethernet (1 - ether)
Capture length = 2048
Time precision = nanoseconds (9)
Time ticks per second = 1000000000
Time resolution = 0x09
Number of stat entries = 0
Number of packets = 20358
数据包文件通过 NPM 回溯分析下载,并根据 IP 通讯对做过特定过滤,且经过 TraceWrangler 匿名化软件处理。捕获总时长 1617 秒,数据包数量 20k 个,速率 44kbps 。
1. 关于 TraceWrangler 匿名化软件简介,可以查看之前的文章《Wireshark 提示和技巧 | 如何匿名化数据包》
2. 另外一个比较特别的地方是 Packet size limit: inferred: 70 bytes - 1518 bytes (range) ,通常来说根据 snaplen 做截断,应该是一个统一的数值,也就是所有的数据包捕获长度应该是一样的,而不是一个范围值,这里是 NPM 回溯分析设备所处理设置的原因。
专家信息如下,有部分协议解析的 Error 问题,以及先前分段未被捕获到、ACK 确认了未被捕获到的分段等 Warning 问题,考虑到 ACKed unseen segment
的现象,更多是包没有捕获到,并不是什么问题。值得关注的是 TCP 新连接信息使用同样端口、Dup ACK 以及重传信息,有一定数量,需进一步分析。
正常情况下的数据包交互如下,可以看到从 TCP 三次握手,数据交互,再到 TCP 四次挥手,整个过程很顺畅。
实际协议为 HTTP,只不过服务端口为 8085 ,wireshark 识别为 WOWW 协议,可以通过 Decode As... 更改,本篇非重点,并未更改。
再到问题数据包交互,可以看到如下现象:
-
对端 F5 负载均衡侧首先发出 FIN,之后间隔很长时间约 135s 后,客户端才发出 FIN;
-
此时由于未知原因,对端并未对客户端 FIN 做出 ACK 确认,因此 FIN 不断产生重传,到最后客户端超时连接拆除;
-
过了一段时间后,客户端重新以同样的源端口 40040 发起访问,但此时无法建连成功,SYN 不断产生重传后无果;
-
此后产生反复,客户端建连一直无法成功,一直到最后间隔 537s 后,客户端才重新建连成功。
实际到此,再结合文章主题和网络拓扑,有经验的同学应该已经知道问题的所在和相关数据包现象。但考虑到对问题的完整分析,一般需在客户端和服务器端同时抓包,以对比得出比较明确的结论,所以要求客户端业务容器同事也在客户端上抓包,并且网络在 F5 负载均衡所在的核心交换机上通过流量镜像也引到了科来 NPM 回溯分析设备上,这样在故障时点可以通过 NPM 设备上调取相关数据包进行对比分析。
阶段二
客户端
首先客户端业务容器提供了相关应用上的故障日志和时间点,同时也提供了相关故障时点的数据包跟踪文件。
数据包文件基本信息如下:
λ capinfos 客户端容器.pcapng
File name: 客户端容器.pcapng
File type: Wireshark/... - pcapng
File encapsulation: Linux cooked-mode capture v1
File timestamp precision: microseconds (6)
Packet size limit: file hdr: (not set)
Number of packets: 2937
File size: 1308 kB
Data size: 1177 kB
Capture duration: 6684.080012 seconds
First packet time: 2023-03-16 09:14:32.821707
Last packet time: 2023-03-16 11:05:56.901719
Data byte rate: 176 bytes/s
Data bit rate: 1409 bits/s
Average packet size: 401.02 bytes
Average packet rate: 0 packets/s
SHA256: 155c3e2f8b60465a85eab5e6eddb2eb3a7531ec2fc1b299b25bb2998d7e32188
RIPEMD160: ec53b44d06f6899784d3f0db35a6f90d15d0aa5c
SHA1: 0ba9bb261c5de9586c6543d09e88d04f699d5714
Strict time order: False
Capture application: Editcap (Wireshark) 4.0.4 (v4.0.4-0-gea14d468d9ca)
Capture comment: Sanitized by TraceWrangler v0.6.8 build 949
Number of interfaces in file: 1
Interface #0 info:
Encapsulation = Linux cooked-mode capture v1 (25 - linux-sll)
Capture length = 262144
Time precision = microseconds (6)
Time ticks per second = 1000000
Time resolution = 0x06
Number of stat entries = 0
Number of packets = 2937
可以看到数据包文件是在 Linux 系统上通过 tcpdump 抓取,且文件封装方式是 Linux cooked-mode capture v1 ,说明是 tcpdump -i any 命令捕获。捕获总时长 6684 秒,数据包数量 2937 个,速率 1409 bps 很低。
专家信息如下,有很多的(疑似)快速重传、重传信息、Dup ACK等,考虑到总数据包数量不到 3000,重传数量未免过多了。
统计会话信息中,仅有客户端业务容器 192.168.0.1 至 F5 负载均衡 VIP 10.10.10.1 的连接信息,固定源和目的端口,说明 tcpdump 上抓取也做了一定过滤。
打开数据包跟踪文件后,映入眼帘的就是一片红黑色,N 多的 TCP 重传信息,但实际上仔细看每个数据帧的间隔时间,它实际上并不是真正的重传数据包。
结合上述信息,推断客户端业务容器所执行的 tcpdump 命令可能如下,该命令因为 -i any 选取所有网卡的原因,所抓取的数据包有重复,通过 ip.id 信息也可以判断,一模一样。
tcpdump -i any host 10.10.10.1 and port 8085 -w xxx.pcapng
考虑到客户端业务容器捕获数据包重复,可以有两个方式处理:
-
加工处理删除重复数据包,像是 editcap 或是 tshark 脚本命令;
-
客户端业务容器根据实际网卡 -i xxx网卡重新捕获。
简单去重后的数据包跟踪文件如下,可以看到客户端业务容器捕获的数据包是同样的现象,较大延迟之后的客户端 FIN 不断重传,再之后新的 SYN 无法连接,直到最后经过一个较大的间隔时间之后,才能重新成功建立连接。
F5 负载均衡
转到 F5 负载均衡侧,也就是在 F5 负载均衡入方向所捕获的数据包,通过 tcp.port == 51920 进行相关过滤后,如下:
主要现象如下:
-
本端 F5 负载均衡侧首先发出 FIN,但接收到对 FIN 的 ACK 确认之后,并没有收到客户端所发送的 FIN (此处对应客户端 FIN 不断重传的现象,实际上 F5 负载均衡并没有收到),初步可以确认是防火墙问题;
-
在 288s 之后收到了客户端所发送的 SYN ,但是 F5 是以 ACK 回复(此处对应客户端并没有收到相关 ACK);
-
此后产生反复,不断收到客户端的 SYN,但是始终以 ACK 回复,也再没有任何之后的交互现象;
-
因本端取包的时间并没有那么长,所以没有抓到经过较大间隔后,客户端 SYN 重新建连成功的现象,这个并无问题。
汇总分析
综合以上客户端业务容器和 F5 负载均衡上的抓包信息和现象,总结以下问题结论:
-
业务访问链:客户端业务容器 - 防火墙 - F5 负载均衡 - Nginx - 服务器,此处 F5 负载均衡为 4 层方式;
-
问题产生的根因:客户端业务容器 FIN,也就是 TCP 四次挥手中的第三次,间隔太长时间才发出,但此时防火墙由于空闲会话超时,该连接已删除,所以产生了两端的异常数据包现象;
-
数据包完整交互过程,分析如下:
-
第一次 TCP 正常三次握手建连,完成正常的数据交互后,首先 Nginx(或者服务器)空闲会话超时,也就是看到的第一个大间隔约 120s ,发出了 FIN,经过 F5 负载均衡转发,到达客户端,客户端正常回复了 ACK;(此时整个交互都正常)
-
此时由于该 TCP 连接没有任何数据包交互,首先防火墙达到了空闲会话超时时间,该连接删除;
-
之后客户端业务容器的 FIN 才姗姗来迟,但由于防火墙已经没有了该连接信息,所以该 FIN 数据包无法通过防火墙,因此在客户端会不断重传 FIN 无法得到回应后,客户端连接也删除,而同样在 F5 负载均衡侧也就是 Nginx 服务器上无法收到任何数据包,该连接仍然处于 FIN_WAIT_2 状态下;
-
又经过一段时间,客户端重新以同样的源端口发起 SYN 连接,对于防火墙来说属于新连接放行,此时新的 SYN 数据包经 F5 负载均衡到达了 Nginx 服务器,但 Nginx 上仍处于上一个连接中,在收到 SYN 之后是以上一个连接中的信息回复 ACK,但同样该 ACK 数据包无法通过防火墙,所以在客户端上看到的是 SYN 不断重传无法建立连接,而在 F5 负载均衡侧是不断收到 SYN 然后回复 ACK,但是无任何之后的信息;
-
之后在一个较大间隔时间没有任何数据包交互后,在 Nginx 或是 F5 负载均衡上一个连接同样达到了超时,进而删除,之后客户端再发起的新连接才得以成功。
问题总结
近期因防火墙空闲会话超时所产生的问题感觉还挺多,最终解决的方式也一样,之后在防火墙上针对该业务容器 IP 通讯单独调整了空闲会话时间限制,至此业务系统恢复正常,但问题的根因,产生 FIN 延迟的问题仍需要业务研发进一步定位和处理。
往期推荐
原文始发于微信公众号(Echo Reply):Wireshark TS | 防火墙空闲会话超时问题
- 左青龙
- 微信扫一扫
-
- 右白虎
- 微信扫一扫
-
评论