前段時間在跟蹤一個RDP應用的問題,RDP應用在過裝置透明代理處理後速度變得比不過要慢的多,至少一半以上。嫌RDP每次使用太麻煩了,於是使用了一簡單的TCP發包服務端和收包用戶端,用來類比RDP的資料流,加快測試的效率。結果發現最簡單的發包應用經過透明代理後就會慢上3s左右,一開始以為這是代理處理帶來的處理時延,每個包的處理時延累加起來就達到的這個數字,後來抓包看了下發現不對,於是使用Linux做發包的服務端,Windows做用戶端,串連時抓包如下:
-bash-2.05b# tcpdump -i eth0 port 8888 -nn -c 20
tcpdump: listening on eth0
15:24:16.709831 192.168.0.148.60320 > 192.168.3.121.8888: S 1286639064:1286639064(0) win 8192 <mss 1460,nop,nop,sack,nop,wscale 8> (DF)
15:24:16.713211 192.168.3.121.8888 > 192.168.0.148.60320: S 1778803221:1778803221(0) ack 1286639065 win 5840 <mss 1460,nop,nop,sackOK,nop,wscale 7>
15:24:16.709831 192.168.0.148.60320 > 192.168.3.121.8888: . ack 1 win 256 (DF)
15:24:19.740047 192.168.3.121.8888 > 192.168.0.148.60320: P 1:257(256) ack 1 win 45
15:24:19.929831 192.168.0.148.60320 > 192.168.3.121.8888: . ack 257 win 255 (DF)
15:24:19.936427 192.168.3.121.8888 > 192.168.0.148.60320: P 257:1461(1204) ack 1 win 45
15:24:19.936538 192.168.3.121.8888 > 192.168.0.148.60320: P 1461:1601(140) ack 1 win 45
15:24:19.929831 192.168.0.148.60320 > 192.168.3.121.8888: . ack 1601 win 256 (DF)
15:24:19.929831 192.168.0.148.60320 > 192.168.3.121.8888: P 1:21(20) ack 1601 win 256 (DF)
15:24:19.937526 192.168.3.121.8888 > 192.168.0.148.60320: . ack 21 win 45
15:24:19.929831 192.168.0.148.60320 > 192.168.3.121.8888: P 21:41(20) ack 1601 win 256 (DF)
15:24:19.937731 192.168.3.121.8888 > 192.168.0.148.60320: . ack 41 win 45
15:24:19.929831 192.168.0.148.60320 > 192.168.3.121.8888: P 41:61(20) ack 1601 win 256 (DF)
15:24:19.937927 192.168.3.121.8888 > 192.168.0.148.60320: . ack 61 win 45
15:24:19.966700 192.168.3.121.8888 > 192.168.0.148.60320: . 1601:3061(1460) ack 61 win 45
15:24:19.966830 192.168.3.121.8888 > 192.168.0.148.60320: P 3061:3201(140) ack 61 win 45
問題出現在三向交握過程的第三個包和服務端發送的第一個包上,中間有一個3s的間隔,上層的服務端在acceept後,就立即發送資料了,沒有任何的時延。為了確定延遲在何處引發的,在上層加了些調試資訊,同時在LOCAL_OUT的最高優先順序上註冊了鉤子函數來列印一些調試資訊,結果表明延遲只可能發生在TCP協議棧中。
同時還有一個奇怪的現象,上層發的包長度都是1600位元組,按道理TCP根據MSS拆包發送出去的包應該是1460+140的組合方式,這個從後面的包可以看出來,但是產生延遲的包被發送出去的時候的拆分方式卻是256+1204+140的方式,而256剛好是三向交握中第三個ACK包攜帶的視窗值,看上去好像是剛好被這個視窗限制了。核心添加調試日誌證明了就是被該視窗限制的,TCP認為超過了對方的接收視窗,導致在上層調用send的時候沒有發送成功,第二次逾時重發,同時拆包發送出去的。
在三向交握中可以看到有wscale的選項的,256<<8=65536,而不是256的,看來這個視窗擴大選項處理出現了問題。把TCP的建立流程再詳細的跟蹤一遍,主要看處理snd_wnd的地方,在tcp_rcv_state_process()裡面發現,處理三向交握的第三個ACK包時,赫然一句:
tp->snd_wnd = ntohs(th->window);
這個地方應該是需要考慮視窗擴大選項的,不太相信Linux有這個大的一個BUG,去lxr上翻看Linux的原始代碼,發現卻是:
tp->snd_wnd = ntohs(th->window) << tp->snd_wscale;
最終發現是我們打的WEB100補丁上把這句話給修改了,補丁的這部分代碼如下:
代碼 tp->snd_una = TCP_SKB_CB(skb)->ack_seq;
- tp->snd_wnd = ntohs(th->window) << tp->snd_wscale;
+ WEB100_VAR_SET(tp, SndUna, tp->snd_una);
+ /* RFC1323: The window in SYN & SYN/ACK segments is
+ * never scaled (PSC/CMU patch {rreddy,mathis}@psc.edu).
+ */
+
+ tp->snd_wnd = ntohs(th->window);
+ WEB100_UPDATE_FUNC(tp, web100_update_rwin_rcvd(tp));
Google了一把,發現是這個是比較老的Web100的補丁上有的代碼,新的好像沒有這個代碼了。
修改後測試,3s的時延消除。但是RDP慢上一半,3s的時延消除影響不大,下篇繼續。