云计算之路-阿里云上:Wireshark抓包分析一个耗时20秒的请求

这篇博文分享的是我们针对一个耗时20秒的请求,用Wireshark进行抓包分析的过程。

请求的流程是这样的:客户端浏览器 -> SLB(负载均衡) -> ECS(云服务器) -> SLB -> 客户端浏览器。

下面是分析的过程:

1. 启动Wireshark,针对内网网卡进行抓包。

2. 在IIS日志中找出要分析的请求(借助Log Parser Studio)

通过c-ip(Client IP Address)可以获知SLB的内网IP,在分析Wireshar抓包时需要依据这个IP进行筛选。

通过sc-bytes(Bytes Sent)可以得知请求的响应内容的长度大于1MB,这可能是触发问题的一个条件。

3. 停止Wireshark抓包

4. 在Wireshark的Filter中输入ip.src==10.159.63.237 or ip.dst==10.159.63.237,筛选出针对10.159.63.237这个IP的包。

5. 根据IIS日志中的时间点找出Wireshark中对应的包(最终完成响应内容发送的包):

6. 然后Follow TCP Steam,只列出这个TCP流上的包,这样就可以方便地找出发起请求的包:

看到这个包中的TCP Window size只有29,感觉有些小。我们又专门抓包测试了一下Mac OS X与Windows,Mac OS X的起始TCP Window size是8192,Windows是256。

看了一下之前的SYN/ACK包,才知道了怎么回事?

SLB->ECS,[SYN],TCP Window size:14600
ECS->SLB, [SYN,ACK] TCP Window size:8192
SLB->ECS, [ACK] TCP Window size:29

SLB在SYN时设置的TCP Window size是14600,而ECS中的Windows Server 2012回SYN/ACK时给的TCP Window size是8192,由于SLB的Window size scaling factor是512,于是14600/512就是28了。这地方可以考虑在Windows中将TCP Window size改大一些。

关于TCP Window,推荐阅读园子里Vamei写的博文——协议森林10 魔鬼细节 (TCP滑窗管理)

7. 由于响应内容大于1MB,远远超出了TCP的MSS(Maxitum Segment Size),要进行TCP segment of a reassembled PDU,所以接下来出现了有一堆的TCP segment of a reassembled PDU包。

8. 在发送TCP segment of a reassembled PDU的过程中出现了重复的ACK包

这说明了当时网络环境出了某种问题。

9. 再接下来出现了[TCP Out-Of-Order],服务端收到的TCP包的次序不对,出现的时间点是14:36:26.993176,至此已经耗时84ms。

这里也说明了当时网络环境出了某种问题。

10. 继续发送TCP segment of a reassembled PDU,结果在14:36:27.060223又出现[TCP Dup ACK ]:

11. 接着又出现了[TCP Out-Of-Order]。

12. 接下来SLB给ECS发了一个致命的ACK包,Window Size竟然只有2

这时服务端估计郁闷极了,就如同跟着宝马开车,突然前面的宝马踩了个急刹车。

(注:SLB这么做,也有可能是客户端网络环境的原因)

13. 过了500多ms之后,SLB给ECS发了一个[TCP Window Update]包,将TCP window size改为了36。

14:36:27.779925000    10.159.63.237    10.161.241.208    TCP    66    [TCP Window Update] 14319 > http [ACK] Seq=313 Ack=922921 Win=18432 Len=0 TSval=173285669 TSecr=18155162

14. 交通恢复正常。。。

15. 突然宝马又踩了一次急刹车,TCP window又变成了2:

14:36:27.862061000    10.159.63.237    10.161.241.208    TCP    66    14319 > http [ACK] Seq=313 Ack=957673 Win=1024 Len=0 TSval=173285752 TSecr=18155225

16. 700多ms后的[TCP Window Update]又让交通恢复正常。

17. 就这样反复地踩刹车、加速。。。。

18. 直到了14:36:47,才完成了整个响应内容的发送,而时间已经过去近21秒。

从分析的情况看,SLB与客户端的网络环境都可能引起这个问题。但是从IIS日志来看,有些耗时长的请求竟然达到了140秒,什么样的客户端会傻到一直等2分多钟而不断开TCP连接或重发请求?

posted @ 2014-06-15 17:30  博客园团队  阅读(23669)  评论(6编辑  收藏  举报