問題描述
客戶使用(yong)redis服務,LB后端(duan)掛載16臺redis db,當連接空閑5分鐘后,客戶端(duan)再(zai)次寫(xie)數據時,redishuirst報(bao)文,客戶端(duan)報(bao) conntion rst by peer 異常。
問題分析
如果redis server的(de)(de)連接(jie)(jie)在(zai)(zai)5分鐘之(zhi)內沒有任何數據(ju)的(de)(de)傳輸,sever會主動調用close()將(jiang)連接(jie)(jie)關(guan)閉(bi)(tcp經(jing)過4次握手正常關(guan)閉(bi)連接(jie)(jie)),不會出現client的(de)(de)異常斷(duan)開,在(zai)(zai)server端抓包發現redis向client的(de)(de)發送的(de)(de)fin + ack包一直在(zai)(zai)重傳直到超時,所以(yi)當client,再(zai)次嘗試發送數據(ju)時,此連接(jie)(jie)被redis reset了。

問題定位過程
初步分析
通過抓包看,fin + ack在有重傳而且重傳了很多次,所以判斷server到client此方向的鏈路上,包被丟棄了
1. 首先懷疑是公網ip的帶寬不夠,通過sar命令查看,業務的流量不是很大,排除是QoS問題。
2. 因為先前出現過一例因為ct檢測連接時checksum的不對將丟棄fin + ack的包,所以懷疑是ovs將包丟棄了,通過tcpdump確認的確是ovs的ct將包丟棄了,所以我們關閉了ct checksum檢查,然后觀察問題是否還會出現,同時我們也在測試環境復現此問題。
3. 修改了(le)checksum后,問題未復(fu)現(xian),可(ke)能(neng)和(he)問題的發生頻率有(you)關系,幸運(yun)的事(shi),我們在(zai)測試(shi)環境很快便復(fu)現(xian)此問題。

redis: 10.0.1.64,client: 10.226.192.70
10.0.1.64 --> 10.226.192.70的fin+ack有tcp 重傳,但是(shi)10.226.192.70 <--> 10.0.1.64發送的keep-alive是(shi)正常(chang)的。
測試環境debug
測試環境復現了之后,關閉ct的checksum,關閉方式如下命令(ling):
sysctl -w net.netfilter.nf_conntrack_checksum=0問題(ti)依然存在,確定不是checksum的問題(ti),在ct的tcp有一個參數(shu)超時時間(jian)設置(zhi)正是5分鐘,然后我們將其修改為10分鐘,如下命(ming)令:
sysctl -w net.netfilter.nf_conntrack_tcp_timeout_unacknowledged=600問題(ti)不復(fu)現,懷疑此問題(ti)和(he)此參數的設置有關系,因為(wei)我(wo)們在client開啟了10個(ge)連(lian)接(jie),但(dan)是只有個(ge)別(bie)的連(lian)接(jie)異(yi)常,不是所(suo)有的,為(wei)了進一(yi)步(bu)確認,我(wo)們將超時(shi)時(shi)間由5分鐘修改(gai)為(wei)2分鐘,如下命令:
sysctl -w net.netfilter.nf_conntrack_tcp_timeout_unacknowledged=120發現這10個連接都出現了異常,所以確定是nf_conntrack_tcp_timeout_unacknowledged的設置導致的。
分析代碼此(ci)(ci)(ci)參數的功能(neng):如果發送的報(bao)文攜(xie)帶了數據(ju),那(nei)么此(ci)(ci)(ci)數據(ju)必須(xu)在nf_conntrack_tcp_timeout_unacknowledged時間內被(bei)ACK,也就是T4-T2<nf_conntrack_tcp_timeout_unacknowledged, 否則將此(ci)(ci)(ci)session從ct表中刪除。

修改ct的超時時間
當current end sequence > last end sequence時,發送的時候設置IP_CT_TCP_FLAG_DATA_UNACKNOWLEDGED標記。
當current ack sequence == last end sequence時,接收的時候清除IP_CT_TCP_FLAG_DATA_UNACKNOWLEDGED此(ci)標(biao)記,
當設置了IP_CT_TCP_FLAG_DATA_UNACKNOWLEDGED標記后,ct的timeout更新(xin)為nf_conntrack_tcp_timeout_unacknowledged(默認5分鐘)。
因為fin+ack的(de)(de)報文被(bei)drop了,而且redis發(fa)送(song)的(de)(de)fin+ack距離上(shang)一個ack報文的(de)(de)時間間隔(ge)是(shi)(shi)5分鐘,所(suo)以懷疑是(shi)(shi)redis發(fa)送(song)的(de)(de)ack報文或是(shi)(shi)push+ack報文有問題,需要check這兩種(zhong)報文的(de)(de)sequence是(shi)(shi)否正(zheng)確(que),然后將(jiang)netfilter的(de)(de)pr_debug日志(zhi)打開(kai),如(ru)下(xia):
PSH+ACK:
[2051865.254109] tcp_in_window: START
[2051865.254119] tcp_in_window:
[2051865.254119] seq=984687149 ack=57047932+(0) sack=57047932+(0) win=58
end=984687154
[2051865.254129] tcp_in_window: sender end=984687149 maxend=984716845
maxwin=29696 scale=9 receiver en #sender end > end, 配置send->flags
d=57047932 maxend=57077628 maxwin=29696 scale=9
[2051865.254138] tcp_in_window:
[2051865.254138] seq=984687149 ack=57047932+(0) sack=57047932+(0) win=58
end=984687154
[2051865.254147] tcp_in_window: sender end=984687149 maxend=984716845
maxwin=29696 scale=9 receiver en
d=57047932 maxend=57077628 maxwin=29696 scale=9
[2051865.254151] tcp_in_window: I=1 II=1 III=1 IV=1
[2051865.254161] tcp_in_window: res=1 sender end=984687154 maxend=984716845
maxwin=29696 receiver end=57047932 maxend=57077628 maxwin=29696
ACK:
[2051865.254414] tcp_in_window: START
[2051865.254426] tcp_in_window:
[2051865.254426] seq=57047932 ack=984687154+(0) sack=984687154+(0) win=58
end=57047938
[2051865.254436] tcp_in_window: sender end=57047932 maxend=57077628 maxwin=29696
scale=9 receiver end=984687154 maxend=984716845 maxwin=29696 scale=9 #receiver
end== ack, 清除receiver->flags, 同時sender end > end, 配置send->flags
[2051865.254451] tcp_in_window:
[2051865.254451] seq=57047932 ack=984687154+(0) sack=984687154+(0) win=58
end=57047938
[2051865.254464] tcp_in_window: sender end=57047932 maxend=57077628 maxwin=29696
scale=9 receiver end=984687154 maxend=984716845 maxwin=29696 scale=9
[2051865.254470] tcp_in_window: I=1 II=1 III=1 IV=1
[2051865.254483] tcp_in_window: res=1 sender end=57047938 maxend=57077628
maxwin=29696 receiver end=984687154 maxend=984716850 maxwin=29696在wrireshark里ack報文的seq為57047932,data len=0, 所以end = seq + data len= 57047932, 但是日志(zhi)里end=57047938, data len= end - seq = 6, 多了6個字節(jie)的數據, 所以ct一(yi)直在等待此6字節(jie)的數據被ack,但實(shi)際上(shang)接收端不會發送(song)此ack,直到(dao)5分鐘到(dao)期,session被刪除。

在ACK報文的二層頭里邊的padding的數據正好是6字節,懷疑是ct將此6字節的pading當數據處理了。
這(zhe)里說一下當以太網報(bao)文的(de)(de)的(de)(de)長度小(xiao)于(yu)64字節的(de)(de)時候,網卡會在二層報(bao)文的(de)(de)最后添加padding使報(bao)文的(de)(de)長度大(da)于(yu)或等(deng)于(yu)64字節。

那ct為(wei)什么會將(jiang)報文的padding作為(wei)數(shu)據呢,通(tong)過systemtap和review netfilter的代(dai)碼發現,在(zai)ct在(zai)處理skb的時候,其skb->len是46,正確(que)的值應該為(wei)40,然后繼續(xu)分析skb->len,最后追溯到(dao)ovs的ovs_ct_execute()函(han)數(shu)里(li)
ovs提交給CT的skb->len為46,所以ct處理L3的報文,計算skb->len時并沒有去掉padding的len,導致ct將pading作為數據了。
線上ovs的master代碼,如下,已(yi)經去(qu)掉了(le)(le)paddingd的len了(le)(le)
函數ovs_skb_network_trim()計(ji)算去(qu)掉padding后的skb->len,至(zhi)此問題已定位解決(jue)。