[轉帖]直擊案發現場！TCP 10倍延遲的真相是？

時間 2019-11-06

原文原文鏈接

直擊案發現場！TCP 10倍延遲的真相是？

http://zhuanlan.51cto.com/art/201911/605268.htm

內核參數調優 很是重要啊.

什麼是經驗?就是遇到問題，解決問題，總結方法。遇到的問題多了，解決的辦法多了，經驗天然就積累出來了。今天的文章是阿里技術專家蟄劍在工做中遇到的一個問題引起的對TCP性能和發送接收Buffer關係的系列思考(問題：應用經過專線從公司訪問阿里雲上的服務，專線100M，時延20ms，一個SQL查詢了22M數據出現10倍+的信息延遲，不正常。)但願，你也能從中獲得啓發。python

前言mysql

本文但願解析清楚，當咱們在代碼中寫下 socket.setSendBufferSize 和 sysctl 看到的rmem/wmem系統參數以及最終咱們在TCP經常談到的接收發送窗口的關係，以及他們怎樣影響TCP傳輸的性能。sql

先明確一下：文章標題中所說的Buffer指的是sysctl中的 rmem或者wmem，若是是代碼中指定的話對應着SO_SNDBUF或者SO_RCVBUF，從TCP的概念來看對應着發送窗口或者接收窗口。緩存

TCP性能和發送接收Buffer的關係服務器

相關參數：網絡

$sudo sysctl -a | egrep "rmem|wmem|adv_win|moderate"
net.core.rmem_default = 212992
net.core.rmem_max = 212992
net.core.wmem_default = 212992
net.core.wmem_max = 212992
net.ipv4.tcp_adv_win_scale = 1
net.ipv4.tcp_moderate_rcvbuf = 1
net.ipv4.tcp_rmem = 4096 87380 6291456
net.ipv4.tcp_wmem = 4096 16384 4194304
net.ipv4.udp_rmem_min = 4096
net.ipv4.udp_wmem_min = 4096
vm.lowmem_reserve_ratio = 256 256 32

先從碰到的一個問題看起：app

應用經過專線從公司訪問阿里雲上的服務，專線100M，時延20ms，一個SQL查詢了22M數據，結果花了大概25秒，這太慢了，不正常。若是經過雲上client訪問雲上服務那麼1-2秒就返回了(說明不跨網絡服務是正常的)。若是經過http或者scp從公司向雲上傳輸這22M的數據大概兩秒鐘也傳送完畢了(說明網絡帶寬不是瓶頸)，因此這裏問題的緣由基本上是咱們的服務在這種網絡條件下有性能問題，須要找出爲何。ssh

抓包 tcpdump+wiresharksocket

這個查詢結果22M的須要25秒，以下圖(wireshark 時序圖)，橫軸是時間，縱軸是sequence number：tcp

粗一看沒啥問題，由於時間太長掩蓋了問題。把這個圖形放大，就看中間50ms內的傳輸狀況(橫軸是時間，縱軸是sequence number，一個點表明一個包)。

換個角度，看看窗口尺寸圖形：

從bytes in flight也大體能算出來總的傳輸時間 16K*1000/20=800Kb/秒咱們的應用會默認設置 socketSendBuffer 爲16K：

socket.setSendBufferSize(16*1024) //16K send buffer

來看一下tcp包發送流程：

圖片來源：陶輝

若是sendbuffer不夠就會卡在上圖中的第一步 sk_stream_wait_memory，經過systemtap腳本能夠驗證：

#!/usr/bin/stap
# Simple probe to detect when a process is waiting for more socket send
# buffer memory. Usually means the process is doing writes larger than the
# socket send buffer size or there is a slow receiver at the other side.
# Increasing the socket's send buffer size might help decrease application
# latencies, but it might also make it worse, so buyer beware.
# Typical output: timestamp in microseconds: procname(pid) event
#
# 1218230114875167: python(17631) blocked on full send buffer
# 1218230114876196: python(17631) recovered from full send buffer
# 1218230114876271: python(17631) blocked on full send buffer
# 1218230114876479: python(17631) recovered from full send buffer
probe kernel.function("sk_stream_wait_memory")
{
printf("%u: %s(%d) blocked on full send buffern",
gettimeofday_us(), execname(), pid())
}
probe kernel.function("sk_stream_wait_memory").return
{
printf("%u: %s(%d) recovered from full send buffern",
gettimeofday_us(), execname(), pid())
}

原理解析

若是tcp發送buffer也就是SO_SNDBUF只有16K的話，這些包很快都發出去了，可是這16K不能當即釋放出來填新的內容進去，由於tcp要保證可靠，萬一中間丟包了呢。只有等到這16K中的某些包ack了，纔會填充一些新包進來而後繼續發出去。因爲這裏rt基本是20ms，也就是16K發送完畢後，等了20ms才收到一些ack，這20ms應用、內核什麼都不能作，因此就是如第二個圖中的大概20ms的等待平臺。

sendbuffer至關於發送倉庫的大小，倉庫的貨物都發走後，不能當即騰出來發新的貨物，而是要等對方確認收到了(ack)才能騰出來發新的貨物。傳輸速度取決於發送倉庫(sendbuffer)、接收倉庫(recvbuffer)、路寬(帶寬)的大小，若是發送倉庫(sendbuffer)足夠大了以後接下來的瓶頸就是高速公路了(帶寬、擁塞窗口)。

若是是UDP，就沒有可靠的概念，有數據通通發出去，根本不關心對方是否收到，也就不須要ack和這個發送buffer了。

幾個發送buffer相關的內核參數：

vm.lowmem_reserve_ratio = 256 256 32
net.core.wmem_max = 1048576
net.core.wmem_default = 124928
net.ipv4.tcp_wmem = 4096 16384 4194304
net.ipv4.udp_wmem_min = 4096

net.ipv4.tcp_wmem 默認就是16K，並且是可以動態調整的，只不過咱們代碼中這塊的參數是不少年前從Cobra中繼承過來的，初始指定了sendbuffer的大小。代碼中設置了這個參數後就關閉了內核的動態調整功能，可是能看到http或者scp都很快，由於他們的send buffer是動態調整的，因此很快。

接收buffer是有開關能夠動態控制的，發送buffer沒有開關默認就是開啓，關閉只能在代碼層面來控制：

net.ipv4.tcp_moderate_rcvbuf

優化

調整 socketSendBuffer 到256K，查詢時間從25秒降低到了4秒多，可是比理論帶寬所須要的時間略高。

繼續查看系統 net.core.wmem_max 參數默認最大是130K，因此即便咱們代碼中設置256K實際使用的也是130K，調大這個系統參數後整個網絡傳輸時間大概2秒(跟100M帶寬匹配了，scp傳輸22M數據也要2秒)，總體查詢時間2.8秒。測試用的mysql client短鏈接，若是代碼中的是長鏈接的話會塊300-400ms(消掉了慢啓動階段)，這基本上是理論上最快速度了。

若是指定了tcp_wmem，則net.core.wmem_default被tcp_wmem的覆蓋。send Buffer在tcp_wmem的最小值和最大值之間自動調整。若是調用setsockopt()設置了socket選項SO_SNDBUF，將關閉發送端緩衝的自動調節機制，tcp_wmem將被忽略，SO_SNDBUF的最大值由net.core.wmem_max限制。

BDP 帶寬時延積

BDP=rtt*(帶寬/8)

這個 buffer 調到1M測試沒有幫助，從理論計算BDP(帶寬時延積) 0.02秒*(100MB/8)=250Kb 因此SO_SNDBUF爲256Kb的時候基本能跑滿帶寬了，再大實際意義也不大了。也就是前面所說的倉庫足夠後瓶頸在帶寬上了。

由於BDP是250K，也就是擁塞窗口(帶寬、接收窗口和rt決定的)即將成爲新的瓶頸，因此調大buffer沒意義了。

用tc構造延時和帶寬限制的模擬重現環境

sudo tc qdisc del dev eth0 root netem delay 20ms
sudo tc qdisc add dev eth0 root tbf rate 500kbit latency 50ms burst 15kb

這個案例關於wmem的結論

默認狀況下Linux系統會自動調整這個buffer(net.ipv4.tcp_wmem), 也就是不推薦程序中主動去設置SO_SNDBUF，除非明確知道設置的值是最優的。

從這裏咱們能夠看到，有些理論知識點雖然咱們知道，可是在實踐中很難聯繫起來，也就是常說的沒法學以至用，最開始看到抓包結果的時候比較懷疑發送、接收窗口之類的，沒有直接想到send buffer上，理論跟實踐的鴻溝。

說完發送Buffer(wmem)接下來咱們接着一看看接收buffer(rmem)和接收窗口的狀況

用這樣一個案例下來驗證接收窗口的做用：

有一個batch insert語句，整個一次要插入5532條記錄，全部記錄大小總共是376K。SO_RCVBUF很小的時候而且rtt很大對性能的影響

若是rtt是40ms，總共須要5-6秒鐘：

基本能夠看到server一旦空出來點窗口，client立刻就發送數據，因爲這點窗口過小，rtt是40ms，也就是一個rtt才能傳3456字節的數據，整個帶寬才80-90K，徹底沒跑滿。

比較明顯間隔 40ms 一個等待臺階，臺階之間兩個包大概3K數據，總的傳輸效率以下：

斜線越陡表示速度越快，從上圖看總體SQL上傳花了5.5秒，執行0.5秒。

此時對應的窗口尺寸：

窗口由最開始28K(20個1448)很快降到了不到4K的樣子，而後基本遊走在即將滿的邊緣，雖然讀取慢，幸虧rtt也大，致使最終也沒有滿。(這個是3.1的Linux，應用SO_RCVBUF設置的是8K，用一半來作接收窗口)。

SO_RCVBUF很小的時候而且rtt很小時對性能的影響

若是一樣的語句在 rtt 是0.1ms的話：

雖然明顯看到接收窗口常常跑滿，可是由於rtt很小，一旦窗口空出來很快就通知到對方了，因此整個太小的接收窗口也沒怎麼影響到總體性能。

如上圖11.4秒整個SQL開始，到11.41秒SQL上傳完畢，11.89秒執行完畢(執行花了0.5秒)，上傳只花了0.01秒，接收窗口狀況：

如圖，接收窗口由最開始的28K降下來，而後一直在5880和滿了之間跳動：

從這裏能夠得出結論，接收窗口的大小對性能的影響，rtt越大影響越明顯，固然這裏還須要應用程序配合，若是應用程序一直不讀走數據即便接收窗口再大也會堆滿的。

SO_RCVBUF和tcp window full的壞case

上圖中紅色平臺部分，停頓了大概6秒鐘沒有發任何有內容的數據包，這6秒鐘具體在作什麼以下圖所示，能夠看到這個時候接收方的TCP Window Full，同時也能看到接收方(3306端口)的TCP Window Size是8192(8K)，發送方(27545端口)是20480。

這個情況跟前面描述的recv buffer過小不同，8K是很小，可是由於rtt也很小，因此server老是能很快就ack收到了，接收窗口也一直不容易達到full狀態，可是一旦接收窗口達到了full狀態，竟然須要驚人的6秒鐘才能恢復，這等待的時間有點太長了。這裏應該是應用讀取數據太慢致使了耗時6秒才恢復，因此最終這個請求執行會很是很是慢(時間主要耗在了上傳SQL而不是執行SQL)。

實際緣由不知道，從讀取TCP數據的邏輯來看這裏沒有明顯的block，可能的緣由：

request的SQL太大，Server(3306端口上的服務)從TCP讀取SQL須要放到一塊分配好的內存，內存不夠的時候須要擴容，擴容有可能觸發fgc，從圖形來看，第一次滿就卡頓了，並且每次滿都卡頓，不像是這個緣由
request請求一次發過來的是多個SQL，應用讀取SQL後，將SQL分紅多個，而後先執行第一個，第一個執行完後返回response，再讀取第二個。圖形中卡頓前沒有response返回，因此也不是這個緣由。
……其它未知緣由

接收方不讀取數據致使的接收窗口滿同時有丟包發生

服務端返回數據到client端，TCP協議棧ack這些包，可是應用層沒讀走包，這個時候 SO_RCVBUF 堆積滿，client的TCP協議棧發送 ZeroWindow 標誌給服務端。也就是接收端的 buffer 堆滿了(可是服務端這個時候看到的bytes in fly是0，由於都ack了)，這時服務端不能繼續發數據，要等 ZeroWindow 恢復。

那麼接收端上層應用不讀走包可能的緣由：

應用代碼卡頓、GC等等

應用代碼邏輯上在作其它事情(好比Server將SQL分片到多個DB上，Server先讀取第一個分片，若是第一個分片數據很大很大，處理也慢，那麼第二個分片數據都返回到了TCP buffer，也沒去讀取其它分片的結果集，直到第一個分片讀取完畢。若是SQL帶排序，那麼Server。

會輪詢讀取多個分片，形成這種卡頓的機率小了不少

上圖這個流由於應用層不讀取TCP數據，致使TCP接收Buffer滿，進而接收窗口爲0，server端不能再發送數據而卡住，可是ZeroWindow的探測包，client都有正常回復，因此1903秒以後接收方窗口不爲0後(window update)傳輸恢復。

這個截圖和前一個相似，是在Server上(3003端口)抓到的包，不一樣的是接收窗口爲0後，server端屢次探測(Server上抓包能看到)，可是client端沒有回覆 ZeroWindow(也有多是回覆了，可是中間環節把ack包丟了,或者這個探測包client沒收到)，形成server端認爲client死了、不可達之類，進而反覆重傳，重傳超過15次以後，server端認爲這個鏈接死了，粗暴單方面斷開(沒有reset和fin,由於不必，server認爲網絡連通性出了問題)。

等到1800秒後，client的接收窗口恢復了，發個window update給server，這個時候server認爲這個鏈接已經斷開了，只能回覆reset。

網絡不通，重傳超過必定的時間(tcp_retries2)而後斷開這個鏈接是正常的，這裏的問題是：

爲何這種場景下丟包了，並且是針對某個stream一直丟包?

多是由於這種場景下觸發了中間環節的流量管控，故意丟包了(好比proxy、slb、交換機都有可能作這種選擇性的丟包)。

這裏server認爲鏈接斷開，沒有發reset和fin,由於不必，server認爲網絡連通性出了問題。client還不知道server上這個鏈接清理掉了，等client回覆了一個window update，server早就認爲這個鏈接早斷了，忽然收到一個update，莫名其妙，只能reset。

接收窗口和SO_RCVBUF的關係

初始接收窗口通常是 mss乘以初始cwnd(爲了和慢啓動邏輯兼容，不想一會兒衝擊到網絡)，若是沒有設置SO_RCVBUF，那麼會根據 net.ipv4.tcp_rmem 動態變化，若是設置了SO_RCVBUF，那麼接收窗口要向下面描述的值靠攏。

初始cwnd能夠大體經過查看到：

ss -itmpn dst "10.81.212.8"
State Recv-Q Send-Q Local Address:Port Peer Address:Port
ESTAB 0 0 10.xx.xx.xxx:22 10.yy.yy.yyy:12345 users:(("sshd",pid=1442,fd=3))
skmem:(r0,rb369280,t0,tb87040,f4096,w0,o0,bl0,d92)
Here we can see this socket has Receive Buffer 369280 bytes, and Transmit Buffer 87040 bytes.
Keep in mind the kernel will double any socket buffer allocation for overhead.
So a process asks for 256 KiB buffer with setsockopt(SO_RCVBUF) then it will get 512 KiB buffer
space. This is described on man 7 tcp.

初始窗口計算的代碼邏輯，重點在18行：

/* TCP initial congestion window as per rfc6928 */
#define TCP_INIT_CWND 10
/* 3. Try to fixup all. It is made immediately after connection enters
* established state.
*/
void tcp_init_buffer_space(struct sock *sk)
{
int tcp_app_win = sock_net(sk)->ipv4.sysctl_tcp_app_win;
struct tcp_sock *tp = tcp_sk(sk);
int maxwin;
if (!(sk->sk_userlocks & SOCK_SNDBUF_LOCK))
tcp_sndbuf_expand(sk);
//初始最大接收窗口計算過程
tp->rcvq_space.space = min_t(u32, tp->rcv_wnd, TCP_INIT_CWND * tp->advmss);
tcp_mstamp_refresh(tp);
tp->rcvq_space.time = tp->tcp_mstamp;
tp->rcvq_space.seq = tp->copied_seq;
maxwin = tcp_full_space(sk);
if (tp->window_clamp >= maxwin) {
tp->window_clamp = maxwin;
if (tcp_app_win && maxwin > 4 * tp->advmss)
tp->window_clamp = max(maxwin -
(maxwin >> tcp_app_win),
4 * tp->advmss);
}
/* Force reservation of one segment. */
if (tcp_app_win &&
tp->window_clamp > 2 * tp->advmss &&
tp->window_clamp + tp->advmss > maxwin)
tp->window_clamp = max(2 * tp->advmss, maxwin - tp->advmss);
tp->rcv_ssthresh = min(tp->rcv_ssthresh, tp->window_clamp);
tp->snd_cwnd_stamp = tcp_jiffies32;
}

傳輸過程當中，最大接收窗口會動態調整，當指定了SO_RCVBUF後，實際buffer是兩倍SO_RCVBUF，可是要分出一部分(2^net.ipv4.tcp_adv_win_scale)來做爲亂序報文緩存。

net.ipv4.tcp_adv_win_scale = 2 //2.6內核，3.1中這個值默認是1。

若是SO_RCVBUF是8K，總共就是16K，而後分出2^2分之一，也就是4分之一，還剩12K當作接收窗口;若是設置的32K，那麼接收窗口是48K。

static inline int tcp_win_from_space(const struct sock *sk, int space)
{//space 傳入的時候就已是 2*SO_RCVBUF了
int tcp_adv_win_scale = sock_net(sk)->ipv4.sysctl_tcp_adv_win_scale;
return tcp_adv_win_scale <= 0 ?
(space>>(-tcp_adv_win_scale)) :
space - (space>>tcp_adv_win_scale); //sysctl參數tcp_adv_win_scale
}

接收窗口有最大接收窗口和當前可用接收窗口。

通常來講一次中斷基本都會將 buffer 中的包都取走。

綠線是最大接收窗口動態調整的過程，最開始是1460*10，握手完畢後略微調整到1472*10(可利用body增長了12)，隨着數據的傳輸開始跳漲。

上圖是四個batch insert語句，能夠看到綠色接收窗口隨着數據的傳輸愈來愈大，圖中藍色豎直部分基本表示SQL上傳，兩個藍色豎直條的間隔表明這個insert在服務器上真正的執行時間。這圖很是陡峭，表示上傳沒有任何瓶頸。

設置 SO_RCVBUF 後經過wireshark觀察到的接收窗口基本

下圖是設置了 SO_RCVBUF 爲8192的實際狀況：

從最開始的14720，執行第一個create table語句後降到14330，到真正執行batch insert就降到了8192*1.5. 而後一直保持在這個值。

If you set a "receive buffer size" on a TCP socket, what does it actually mean?

The naive answer would go something along the lines of: the TCP receive buffer setting indicates the maximum number of bytes a read() syscall could retrieve without blocking.

Note that if the buffer size is set with setsockopt(), the value returned with getsockopt() is always double the size requested to allow for overhead. This is described in man 7 socket.

總結