Golang CLOSE WAIT 分析

1 背景

線上有一個高併發的 HTTP Go 服務部署在 A 區域，能夠正常提供服務。我們有天將 B 區域的流量也準備切到這個服務的時候，發生了一個很詭異的事情。從 A 區域來的流量全部 200，但是從 B 區域來的流量全部都 502、504。

2 排查過程

2.1 懷疑網路問題

這種從不同區域一部分流量正常，一部分流量異常，第一直覺覺得是異常流量那塊應該是網路問題。所以我們讓運維去異常流量 nginx 機器上，發 telnet 和 curl 到服務上。如圖所示

可以看到 telnet 這個 ip port 埠是通的，說明四層以下網路是通的。但是當我們 curl 到對應服務的時候，發現服務被連線重置。 這時候我們就獻出我們的重啟大法，對該例項進行重啟。發現該例項的 curl 請求恢復。所以就可以直接排除我們的網路問題。這個時候，我們就要思考了，是啥問題讓我們程式出現這種詭異問題。因為我們還留了一臺問題機器。我們開始著手對他進行分析。

2.2 分析問題機器

2.2.1 檢視網路問題

我們在出問題的機器上，檢視網路情況。我們發現有大量的 CLOSE WAIT 現象。

然後我們檢視下 CLOSE WAIT 詳細資訊。

可以看到上面有以下情況

• 第二列是 RECVQ，可以看到有很多都大於 1
• Close Wait，來自於探活的客戶端和 nginx 客戶端
• Close Wait 沒有 pid 號（我這裡有 root 許可權，不要懷疑我是沒許可權看不到 pid 資訊）

第一個說明了 RECVQ 大於 1 的都是 nginx 客戶端，1 的都是探活的客戶端。這一塊說明了 nginx 是被堵住了。

第二個說明了裡面探活的客戶端有 8000 條資訊，nginx 的 close wait 大概 100 多條

第三個說明了沒有 pid 問題，我們待會在後面分析中會提及。

看到這麼多 Close Wait。我們首先要拿出這個四次揮手圖。

這裡要注意，客戶端和服務端是個相對概念。在我們這個問題裡，我們的客戶端是探活服務，服務端是我們的業務服務。通過這個圖，可以知道我們的客戶端是發了 close 包，我們的服務端可能沒有正常響應 ack 或者 fin 包，導致 server 端出現 close wait。

這個 close wait 是沒有 pid 的，並且是探活客戶端導致的，

2.2.2 詭異問題

那不是業務導致，那為什麼會產生這種現象。排查的時候一堆問號，並且還發生很多詭異的事情。

• 我們發現 CLOSE WAIT 的客戶端的埠號，在服務端機器上有，但在客戶端機器上早就消失。CLOSE WAIT 就死在了這臺機器上。
• RECVQ 這麼大，為什麼服務還能正常響應 200
• 為什麼上面 curl 會超時，但是 telnet 可以成功
• 為什麼 CLOSE WAIT 沒有 pid

2.2.3 線上除錯

我們使用了sudo strace -p pid，發現主程式卡住了，想當然的認為自己發現了問題。但實際過程中，這是正常現象，我們框架使用了 golang.org/x/net/netutil 裡的 LimitListener ，當你的 goroutine 達到最大值，那麼就會出現這個阻塞現象，因為沒有可用的 goroutine 了，主程式就卡住了。其他執行緒會提供服務，檢視全部執行緒 trace 指令為sudo strace -f -p pid ，當然也可以檢視單個執行緒的 ps -T -p pid ，然後拿到 spid，在執行 sudo strace -p spid 。這個除錯還是沒有太大用處，所以就想怎麼線上下進行復現。

3 線下復現

復現這個是經過線下抓包，除錯出來的。以下我們寫個簡單程式碼進行復現

3.1 server 端程式碼

package main

import (
    "fmt"
    "golang.org/x/net/netutil"
    "net"
    "net/http"
)

func main()  {
    mux := http.NewServeMux()
    mux.HandleFunc("/hello", func(w http.ResponseWriter,r *http.Request)  {
        fmt.Println("r.Body = ", r.Body)
        fmt.Fprintf(w,"HelloWorld!")
    })

    server := &http.Server{Addr: "", Handler: mux}
    listener, err := net.Listen("tcp4", "0.0.0.0:8880")
    if err != nil {
        fmt.Println("伺服器錯誤")
    }
    // 這個地方要把限制變成1
    err = server.Serve(netutil.LimitListener(listener, 1))
    if err != nil {
        fmt.Println("伺服器錯誤2")
    }
}

3.2 client 端程式碼

package main

import (
    "fmt"
    "io/ioutil"
    "net"
    "net/http"
    "strings"
    "time"
)

var httpclient *http.Client

func main() {
    for i := 0; i < 1000; i++ {
        req, err := http.NewRequest("POST", "http://127.0.0.1:8880/hello", strings.NewReader("{}") )
        if err != nil {
            fmt.Println(err)
            return
        }
        // 長連線
        req.Close = false
        httpclient = &http.Client{}
        resp, err := httpclient.Do(req)
        if err != nil {
            fmt.Println(err)
        }
        defer resp.Body.Close()
        body, err := ioutil.ReadAll(resp.Body)
        if err != nil {
            fmt.Println(string(body))
            fmt.Println(err)
        }

    }
    for i := 0; i < 1000; i++ {
        //time.Sleep(10 * time.Second)
        Dial("127.0.0.1:8880", time.Millisecond*500)
        //time.Sleep(100 * time.Second)
    }

}

// Dial dial 指定的埠，失敗返回錯誤
func Dial(addr string, timeout time.Duration) error {
    conn, err := net.DialTimeout("tcp", addr, timeout)
    fmt.Println("dial err------>", err)
    if err != nil {
        return err
    }
    defer conn.Close()
    return err
}

3.3 描述

我們將服務端程式碼的 server.Serve(netutil.LimitListener(listener, 1)) 裡面的限制設定為 1。然後客戶端程式碼的 http 長連線開啟，先做 http 請求，然後再做 tcp 請求。可以得到以下結果。

3.3.1 輸出顯示

3.3.2 命令列顯示

3.3.3 wireshark 顯示

全部請求報文

一個 http 請求報文

一個 tcp 請求報文

3.4 分析

當我們在服務端設定了 limit 為 1 的時候，意味這我們服務端的最大連線數只能為 1。我們客戶端在使用 http keepalive，會將這個連線佔滿，如果這個時候又進行了 tcp 探活，那麼這個探活的請求就會被堵到 backlog 裡，也就是上面我們看到 3.3.2 中第一個圖，裡面的 RECVQ 為 513。

我們先分析 3.3.3 中的前兩個圖。
黑色部分是 http keepalive，其客戶端埠號為 43340，如圖所示
![image.png]

灰色都是 tcp dial 操作，如圖所示

http keepalive 的 close 報文，如圖所示

紅色的是客戶端發現服務端有問題（客戶端埠為 43346），進行了連線 RST 操作，如圖所示

可以看到我們的 tcp 的 dial 操作，最後都是返回的 RST 操作，而且這個時間點剛好在 http keepalive 之後。接下來我們就看下 http keepalive 和 tcp dial 的詳細報文。

3.3.3 第三個圖，說明 http keepalive 是在他建立連線後，90s 後客戶端發的 close 包。
3.3.3 第四個圖，說明 tcp dial 傳送了三次握手後，一次揮手後，客戶端並沒有立即收到接下來的兩次揮手，而是過了 90s 後，才收到後兩次揮手，導致了客戶端 RST 操作。之所以等待 90s 的時間，是之前 tcp keepalive 的操作剛好進行了 close，goroutine 得到釋放，可以使得 connection 被服務 accept，因此這個時候才能傳送 fin 包。

我們這個時候如果在 RECVQ 不多的情況下。就可以復現一個場景，就是 curl 無法成功，但是 telnet 可以成功，如下所示。

這個和線上情況一樣。

然後我們再來看下為什麼線上 CLOSE_WAIT 在服務端上產生的過程。我們先抓了一個埠為 57688 的請求。可以看到 57688 揮手的時候發給 8880 的 fin 包，但是 8880 只響應了 ack。

所以現場抓包這兩個狀態變為 FIN_WAIT2 和 CLOSE_WAIT

我機器上 linux 配置了 FIN_TIMEOUT 為 40s

過 40s 後，可以看到客戶端的 FIN_WAIT 被回收，只留下了服務端的 CLOSE_WAIT

再過 50s，http 的 keepalive 關閉連線，釋放出 goroutine，tcp 的 fin 包就會發出。最終 CLOSE_WAIT 消失

以上我們把線上大部分場景都復現了，如下所示：

• （復現了）服務端監聽的 RECVQ 比較大
• （復現了）服務端出現了 CLOSE WAIT，帶沒有 pid
• （復現了）服務端出現了 CLOSE WAIT 的埠號，在客戶端找不到
• （復現了）服務端出現了 CLOSE WAIT，telnet 可以成功，但是沒辦法 curl 成功
• （未復現）服務端的 CLOSE WAIT 一直不消失，下文中會解釋，但並不確定

3.5 CLOSE WAIT 不消失的情況

出現這個情況比較極端，而且跟我們業務結合起來，有點麻煩，所以不在處理，請大家仔細閱讀這個文章。https://blog.cloudflare.com/this-is-strictly-a-violation-of-the-tcp-specification/

以上是 CLOSE WAIT 出現的一種場景。並沒有完全驗證這種情況。

4 產生線上問題的可能原因

線上的 nginx 到後端 go 配置的 keepalive，當 GO 的 HTTP 連線數達到系統預設 1024 值，那麼就會出現 Goroutine 無法讓出，這個時候使用 TCP 的探活，將會堵在佇列裡，服務端出現 CLOSE WAIT 情況，然後由於一直沒有釋放 goroutine，導致服務端無法發出 fin 包，一直保持 CLOSE WAIT。而客戶端的埠在此期間可能會被重用，一旦重用後，就造成了混亂。（如果在混亂後，Goroutine 恢復後，服務端過了好久響應了 fin 包，客戶端被重用的埠收到這個包是返回 RST，還是丟棄？這個太不好驗證）。個人猜測是丟棄了，導致服務端的 CLOSE WAIT 一直無法關閉，造成 RECVQ 的一直阻塞。

5 其他問題

• 1. 因為 GO 服務端的 HTTP Keepalive 是使用的客戶端的 Keepalive 的時間，如果客戶端的 Keepalive 存在問題，比如客戶端的 http keepalive 洩露，也會導致服務端無法關閉 Keepalive，從而無法回收 goroutine，當然 go 前面擋了一層 nginx，所以應該不會有這種洩露問題。但保險起見，go 的服務端應該加一個 keepalive 的最大值。例如 120s，避免這種問題。
• 2.GO 服務端的 HTTP chucked 編碼時候，如果客戶端沒有正確將 response 的 body 內容取走，會導致資料仍然在服務端的緩衝區，從而導致無法響應 fin 包，但這個理論上不會出現，並且客戶端會自動的進行 rst，不會影響業務。不過最好避免這種編碼。
• 3 linux keepalive 引數可能需要配置，但不敢完全確信他的作用，如下所示。

6 其他 CLOSE WAIT 延伸

• 如過寫的 http 服務存在業務問題，例如裡面有個死迴圈，無法響應客戶端，也會導致 http 服務出現 CLOSE WAIT 問題，但這個是有 pid 號的。
• 如果我們的業務呼叫某個服務的時候，由於沒發心跳包給服務，會被服務關閉，但我們這個時候沒正確處理這個場景，那麼我們的業務處就會出現 CLOSE WAIT。

資料

• 線上大量 close wait 問題 
• 網路程式設計 tcp 連結 
• tcp close wait 問題 
• tcp keepalive 設定