问题背景
来自于朋友分享的一个案例,某某客户反馈电脑应用软件使用时打开很慢,并提供了一个慢时所捕获的数据包文件以及服务端 IP。以前也说过,所谓的慢有很多种现象,也会有很多原因引起,在没有更多输入条件的情况下,拿到一个数据包捕获文件,如何判断分析,包括一些个人的习惯或者经验,就此简单记录下。
问题信息
数据包跟踪文件信息主要如下:
λ capinfos 0918.pcapng
File name: 0918.pcapng
File type: Wireshark/... - pcapng
File encapsulation: Ethernet
File timestamp precision: microseconds (6)
Packet size limit: file hdr: (not set)
Number of packets: 8976
File size: 7217 kB
Data size: 6913 kB
Capture duration: 246.083460 seconds
First packet time: 2023-xx-xx 11:06:48.091668
Last packet time: 2023-xx-xx 11:10:54.175128
Data byte rate: 28 kBps
Data bit rate: 224 kbps
Average packet size: 770.19 bytes
Average packet rate: 36 packets/s
SHA256: xxxxx
RIPEMD160: xxx
SHA1: xxx
Strict time order: True
Capture hardware: Intel(R) Pentium(R) CPU G3260 xxx
Capture oper-sys: 64-bit Windows 7 Service Pack 1, build xxx
Capture application: Dumpcap (Wireshark) 3.0.0 (v3.0.0-0-g937e33de)
Number of interfaces in file: 1
Interface #0 info:Name = \Device\NPF_xxxxxDescription = 本地连接Encapsulation = Ethernet (1 - ether)Capture length = 262144Time precision = microseconds (6)Time ticks per second = 1000000Time resolution = 0x06Operating system = 64-bit Windows 7 Service Pack 1, build xxxNumber of stat entries = 1Number of packets = 8976
客户端为 win 7 64 位系统(相当的老。。硬件也老),通过 Wireshark 捕获数据包,捕获时长 246s,数据包数量 8976,文件大小 6913kB,平均速率约 224kbps,总体上来说速率很低。
根据 Wireshark 统计功能,可以关注下协议分层和会话等信息。其中协议方面 IPv6 占到 73.1%,IPv4 中 TCP 占 20.6%,具体到 TCP 通讯会话,可以看到 TCP 会话数量 88 算是很多了。
题外话,如果不是说用户提供了服务器 IP,在这些茫茫多的数据包中是很难找到真正想要的信息,这也扯到常见的话题,在复杂的客户端流量情况下,如何有效地进行捕获过滤。
之前提到过复杂的客户端流量,关于捕获上的使用错误,说的是需要避免无效流量。作为服务器端自然不用说,流量更多是来自于实际业务,而客户端就比较有讲究了,更多针对的是办公电脑客户端场景,这种情况下由于自身多应用程序的运行,会产生很多的无效流量,干扰后期的分析。
虽然说分析时可以通过显示过滤表达式过滤,但与其这样,在捕获时保持一个纯粹的故障测试环境,岂不是更好,该关的程序能关则关。
专家信息中也是同样的问题,在客户端复杂流量的情况下,专家信息极其繁杂,并不能很好的辅助判断分析。
因此在类似复杂客户端流量的情况下所捕获的数据包文件,可以通过显示过滤表达式过滤掉部分数据包,格式大同小异,如下可参考
tcp
tcp or icmp or icmpv6!(eth.dst.ig == 1) and !(arp or dns or ntp)
!(arp or stp or dns or ntp)
not arp && not stp && not dns
问题分析
过滤
根据提供的服务器 IP,构建会话 IPv4 过滤表达式。
ip.addr eq 192.168.1.1 and ip.addr eq 100.1.1.1
这样精准过滤后,统计中协议分层和会话信息缩减如下,TCP 数据包 367 个,服务端口 7001 的会话共 4 个,分别为 TCP Stream 1, 47, 78, 81。
此时可以直接在会话上点击右键,根据 TCP Stream ID 进行过滤,也就是一般所说的跟踪流,具体查看有什么问题。
分析
在上述统计信息 TCP 会话中,可见 TCP 4 条流,其中 Stream 78 和 81 的数据包数量分别为 10 和 7 ,明显偏少,可以大概估计并没有数据传输。
根据 TCP 跟踪流显示具体数据包,确实组成简单,基本为 TCP 三次握手以及 TCP 四次挥手阶段数据包。
剩余 TCP Stream 1 和 47,进行依次分析,首先是 TCP Stream 1 ,其中在 Packet Details
中 TCP 会话完整性信息为 Complete, WITH_DATA(47)
,这说明 tcp.completeness 字段值为 47,如下:
- 1 : SYN
- 2 : SYN-ACK
- 4 : ACK
- 8 : DATA
- 16 : FIN
- 32 : RST
1 + 2 + 4 + 8 + 32 = 47 ,也就是 SYN + SYN-ACK + ACK + DATA + RST 的值,说明 TCP Stream 1 是一个带有 Data 的完整 TCP 会话,从 TCP 三次握手,到中间数据传输,再到最后的 TCP RST 结束连接,虽然没有 FIN ,稍显突兀,但并无大碍。
关于 TCP 会话完整性分析介绍 以及 tcp.completeness 的显示过滤表达式使用方法,可见之前的文章 《Wireshark 提示和技巧 | TCP 会话完整性分析》
接着可以简单看下专家信息,是否有一些错误提示,但实际上并无啥特殊信息。
因为反馈的现象是应用使用慢,一般所谓的慢,一种常见的情况是由于数据包出现丢包或超时造成重传,会看到超时重传或者是快速重传,以及其它像是 DUP ACK 等等问题。既然上述专家信息中没有类似现象,那可以通过增加 frame.time_delta_displayed
信息列来辅助分析,检查每个数据包的间隔时间有什么特殊问题。
注:0.096143s,即为 No.42 SYN/ACK 与 No.41 SYN 之间的时间间隔,也就是 0.358735 - 0.262592 = 0.096143。
点击 Time Delta 列,从大小到排列,相邻数据包间隔时间较大的就出现在最上面了。
较大的有三个,第一个 RST 间隔 29 秒,这个比较好理解,在数据传输过程当中,No.180 客户端对服务器传输的数据分段全部 ACK 确认之后,间隔了 29 秒没有任何交互,客户端达到了一种应用超时时间,直接 RST 断开连接,虽然没用 FIN 不太标准,但此处的 29 秒并不是直接导致应用慢的原因。
第二个 2.97 秒就有点问题了,这里在 No.115 客户端 ACK 确认完服务器传输的数据分段后,No.149 客户端自身再发数据的间隔出现了 2.97 秒的延迟,这个慢的问题出现在客户端自身。
第三个 1.04 秒同样,发生在 TLS 握手起始,TCP 完成三次握手后,客户端又产生了一个自身的延迟,在 1.04 秒之后才发起 TLS 协商。
此外间隔较大的时间基本都在 100-200ms 之间,相较于 2.97 秒和 1.04 秒虽然并不夸张,但累积的数量如果较多,在某些情况下也是应用传输慢的原因,此处不展开过多分析,直接再去检查下 TCP Stream 47。
TCP Stream 47 基本与 TCP Stream 1 类似,同样的 TCP 会话完整性值 47(以 RST 结束),无丢包重传等异常信息,以及可见的客户端起始 Client Hello 1.02 秒的延迟。
在经过同样的点击 Time Delta 列,按从大小到排列,问题就显而易见了,排名前 6 的延迟全部来自于客户端自身,除了起始的 Client Hello 之外,在数据传输阶段,客户端自身的问题带来了 5 次较大的延迟。以 48 秒和 25 秒两处为例 ,客户端停顿了很长一段时间之后才有反应。
结合 TCP Stream 1 和 TCP Stream 47 两条流的现象,可以判断问题的根因出现在客户端自身,或是系统问题或是应用问题,需要进一步在客户端上查找原因。
问题总结
数据包不说谎,根据朋友反馈,最终客户在更换了电脑之后,应用慢问题得以解决。