天天看點

記一次Redis連接配接池問題引發的RST

某個項目,因為監控尚不完善,是以我時常會人肉查查狀态,終于有一天發現了異常:

記一次Redis連接配接池問題引發的RST

watch -d -n1 ‘netstat -s | grep reset’

如圖所示,伺服器發送了大量的 reset,在我 watch 的時候還在發,多半有問題。

通過 tcpdump 我們可以簡單抓取一下 RST 包:

shell> tcpdump -nn 'tcp[tcpflags] & (tcp-rst) != 0'           

不過更好的方法是通過 tcpdump 多抓一些流量然後用 wireshark 來分析:

記一次Redis連接配接池問題引發的RST

RST

如圖所示,描述了一個 web 伺服器和一個 redis 伺服器的互動過程,有兩個問題:

  • 在我的場景裡,使用了 lua-resty-redis 連接配接池,為什麼還會發送 FIN 來關閉連接配接?
  • 即便關閉連接配接,為什麼 web 伺服器收到 FIN 後還會發送 RST 補刀?

因為項目代碼比較多,我一時确定不了 lua-resty-redis 連接配接池的問題在哪,是以我打算先搞定為什麼 web 伺服器收到 FIN 後還會發送 RST 補刀的問題。

我們可以通過 systemtap 來查查核心(3.10.0-693)是通過什麼函數來發送 RST 的:

shell> stap -l 'kernel.function("*")' | grep tcp | grep reset
kernel.function("bictcp_hystart_reset@net/ipv4/tcp_cubic.c:129")
kernel.function("bictcp_reset@net/ipv4/tcp_cubic.c:105")
kernel.function("tcp_cgroup_reset@net/ipv4/tcp_memcontrol.c:200")
kernel.function("tcp_fastopen_reset_cipher@net/ipv4/tcp_fastopen.c:39")
kernel.function("tcp_highest_sack_reset@include/net/tcp.h:1538")
kernel.function("tcp_need_reset@net/ipv4/tcp.c:2183")
kernel.function("tcp_reset@net/ipv4/tcp_input.c:3916")
kernel.function("tcp_reset_reno_sack@net/ipv4/tcp_input.c:1918")
kernel.function("tcp_sack_reset@include/net/tcp.h:1091")
kernel.function("tcp_send_active_reset@net/ipv4/tcp_output.c:2792")
kernel.function("tcp_v4_send_reset@net/ipv4/tcp_ipv4.c:579")
kernel.function("tcp_v6_send_reset@net/ipv6/tcp_ipv6.c:888")           

雖然我并不熟悉核心,但并不妨礙解決問題。通過檢視源代碼,可以大緻判斷出 RST 是 tcp_send_active_reset 或者 tcp_v4_send_reset 發送的(看名字 tcp_reset 很像是我們要找的,不過實際上它的作用是收到 RST 的時候需要做什麼)。

為了确認到底是誰發送的,我啟動了兩個指令行視窗:

一個運作 tcpdump:

shell> tcpdump -nn 'tcp[tcpflags] & (tcp-rst) != 0'           

另一個運作 systemtap:

#! /usr/bin/env stap

probe kernel.function("tcp_send_active_reset") {
    printf("%s tcp_send_active_reset\n", ctime())
}

probe kernel.function("tcp_v4_send_reset") {
    printf("%s tcp_v4_send_reset\n", ctime())
}
           

通過對照兩個視窗顯示内容的時間點,最終确認 RST 是 tcp_v4_send_reset 發送的。

接下來确認一下 tcp_v4_send_reset 是誰調用的:

#! /usr/bin/env stap

probe kernel.function("tcp_v4_send_reset") {
    print_backtrace()
    printf("\n")
}

// output

0xffffffff815eebf0 : tcp_v4_send_reset+0x0/0x460 [kernel]
0xffffffff815f06b3 : tcp_v4_rcv+0x5a3/0x9a0 [kernel]
0xffffffff815ca054 : ip_local_deliver_finish+0xb4/0x1f0 [kernel]
0xffffffff815ca339 : ip_local_deliver+0x59/0xd0 [kernel]
0xffffffff815c9cda : ip_rcv_finish+0x8a/0x350 [kernel]
0xffffffff815ca666 : ip_rcv+0x2b6/0x410 [kernel]
0xffffffff81586f22 : __netif_receive_skb_core+0x572/0x7c0 [kernel]
0xffffffff81587188 : __netif_receive_skb+0x18/0x60 [kernel]
0xffffffff81587210 : netif_receive_skb_internal+0x40/0xc0 [kernel]
0xffffffff81588318 : napi_gro_receive+0xd8/0x130 [kernel]
0xffffffffc0119505 [virtio_net]
           

如上所示,tcp_v4_rcv 調用 tcp_v4_send_reset 發送了 RST,看看 tcp_v4_rcv 的源代碼:

int tcp_v4_rcv(struct sk_buff *skb)
{
    ...

    sk = __inet_lookup_skb(&tcp_hashinfo, skb, th->source, th->dest);
    if (!sk)
        goto no_tcp_socket;

process:
    if (sk->sk_state == TCP_TIME_WAIT)
        goto do_time_wait;

    ...

no_tcp_socket:
    if (!xfrm4_policy_check(NULL, XFRM_POLICY_IN, skb))
        goto discard_it;

    if (skb->len < (th->doff << 2) || tcp_checksum_complete(skb)) {
csum_error:
        TCP_INC_STATS_BH(net, TCP_MIB_CSUMERRORS);
bad_packet:
        TCP_INC_STATS_BH(net, TCP_MIB_INERRS);
    } else {
        tcp_v4_send_reset(NULL, skb);
    }

    ...

do_time_wait:

    ...

    switch (tcp_timewait_state_process(inet_twsk(sk), skb, th)) {

        ...

        case TCP_TW_RST:
            goto no_tcp_socket;

        ...

    }

    ...
}
           

有兩處可能會觸發 tcp_v4_send_reset(no_tcp_socket)。先看後面的 tcp_v4_send_reset 代碼,也就是 do_time_wait 相關的部分,隻有進入 TIME_WAIT 狀态才會執行相關邏輯,而本例中發送了 RST,并沒有正常進入 TIME_WAIT 狀态,不符合要求,是以問題的症結應該是前面的 tcp_v4_send_reset 代碼,也就是 __inet_lookup_skb 相關的部分:當 sk 不存在的時候,reset。

不過 sk 為什麼會不存在呢?當 web 伺服器發送 FIN 的時候,進入 FIN_WAIT_1 狀态,當 redis 伺服器回複 ACK 的時候,進入 FIN_WAIT_2 狀态,如果 sk 不存在,那麼就說明 FIN_WAIT_1 或者 FIN_WAIT_2 中的某個狀态丢失了,通過 ss 觀察一下:

shell> watch -d -n1 'ss -ant | grep FIN'           

通常,FIN_WAIT_1 或者 FIN_WAIT_2 存在的時間都很短暫,不容易觀察,不過在本例中,流量比較大,是以沒問題。如果你的環境沒有大流量,也可自己通過 ab/wrk 之類的壓力工具人為給一些壓力。結果發現,可以觀察到 FIN_WAIT_1,但是卻很難觀察到 FIN_WAIT_2,看上去 FIN_WAIT_2 似乎丢失了。

原本以為可能和 linger,tcp_fin_timeout 之類的設定有關,經确認排除嫌疑。彷徨了許久,記起 TIME_WAIT 有一個控制項:tcp_max_tw_buckets,可以用來控制 TIME_WAIT 的數量,會不會與此有關:

shell> sysctl -a | grep tcp_max_tw_buckets
net.ipv4.tcp_max_tw_buckets = 131072

shell> cat /proc/net/sockstat
sockets: used 1501
TCP: inuse 117 orphan 0 tw 127866 alloc 127 mem 56
UDP: inuse 9 mem 8
UDPLITE: inuse 0
RAW: inuse 0
FRAG: inuse 0 memory 0           

對比系統現有的 tw,可以發現已經臨近 tcp_max_tw_buckets 規定的上限,試着提高門檻值,會發現又能觀察到 FIN_WAIT_2 了,甚至 RST 的問題也随之消失。

如此一來, RST 問題算是有眉目了:TIME_WAIT 數量達到 tcp_max_tw_buckets 規定的上限,進而影響了 FIN_WAIT_2 的存在(問題細節尚未搞清楚),于是在 tcp_v4_rcv 調用 __inet_lookup_skb 查找 sk 的時候查不到,最終隻好發送 RST。

結論:tcp_max_tw_buckets 不能太小!

問題到這裡還不算完,别忘了我們還有一個 lua-resty-redis 連接配接池的問題尚未解決。

如何驗證連接配接池是否生效呢?

最簡單的方法是核對連接配接 redis 的 TIME_WAIT 狀态是否過多,肯定的話那麼就說明連接配接池可能沒生效,為什麼是可能?因為在高并發情況下,當連接配接過多的時候,會按照 LRU 機制關閉舊連接配接,此時出現大量 TIME_WAIT 是正常的。

When the connection pool would exceed its size limit, the least recently used (kept-alive) connection already in the pool will be closed to make room for the current connection.

最準确的方法是使用 redis 的 client list 指令,它會列印每個連接配接的 age 連接配接時長。通過此方法,我驗證發現 web 伺服器和 redis 伺服器之間的連接配接,總是在 age 很小的時候就被斷開,說明有問題。

在解決問題前了解一下 lua-resty-redis 的連接配接池是如何使用的:

local redis = require "resty.redis"
local red = redis:new()

red:connect(ip, port)

...

red:set_keepalive(0, 100)           

隻要用完後記得調用 set_keepalive 把連接配接放回連接配接池即可。一般出問題的地方有兩個:

  • openresty 禁用了 lua_code_cache,此時連接配接池無效
  • redis 的 timeout 太小,此時長連結可能會頻繁被關閉

在我的場景裡,如上問題均不存在。每當我一籌莫展的時候我就重看一遍文檔,當看到 connect 的部分時,下面一句話提醒了我:

Before actually resolving the host name and connecting to the remote backend, this method will always look up the connection pool for matched idle connections created by previous calls of this method.

也就是說,即便是短連結,在 connect 的時候也會嘗試從連接配接池裡擷取連接配接,這樣的話,如果是長短連接配接混用的情況,那麼連接配接池裡長連結建立的連接配接就可能會被短連結關閉掉。順着這個思路,我搜尋了一下源代碼,果然發現某個角落有一個短連結調用。

結論:不要混用長短連接配接!

繼續閱讀