這篇博文分享的是我們針對一個耗時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連接或重發請求?