技術解析系列PouchContainer Goroutine Leak 檢測實踐
劃重點
本文將從什麼是 goroutine leak,如何檢測以及常用的分析工具來介紹 PouchContainer 在 goroutine leak 方面的檢測實踐。本文作者聿歌。
0. 引言
PouchContainer 是阿里巴巴集團開源的一款容器運行時產品,它具備強隔離和可移植性等特點,可用來幫助企業快速實現存量業務容器化,以及提高企業內部物理資源的利用率。
PouchContainer 同時還是一款 golang 項目。在此項目中,大量運用了 goroutine 來實現容器管理、鏡像管理和日誌管理等模塊。goroutine 是 golang 在語言層面就支持的用戶態 「線程」,這種原生支持並發的特性能夠幫助開發者快速構建高並發的服務。
雖然 goroutine 容易完成並發或者並行的操作,但如果出現 channel 接收端長時間阻塞卻無法喚醒的狀態,那麼將會出現goroutine leak。 goroutine leak 同內存泄漏一樣可怕,這樣的 goroutine 會不斷地吞噬資源,導致系統運行變慢,甚至是崩潰。為了讓系統能健康運轉,需要開發者保證 goroutine 不會出現泄漏的情況。 接下來本文將從什麼是 goroutine leak, 如何檢測以及常用的分析工具來介紹 PouchContainer 在 goroutine leak 方面的檢測實踐。
1. Goroutine Leak
在 golang 的世界裡,你能支配的土撥鼠有很多,它們既可以同時處理一大波同樣的問題,也可以協作處理同一件事,只要你指揮得當,問題就能很快地處理完畢。沒錯,土撥鼠就是我們常說的
goroutine,你只要輕鬆地 go一下,你就擁有了一隻土撥鼠,它便會執行你所指定的任務:
func main() {
waitCh := make(chan struct{})
go func() {
fmt.Println("Hi, Pouch. I"m new gopher!")
waitCh
}()
}
正常情況下,一隻土撥鼠完成任務之後,它將會回籠,然後等待你的下一次召喚。但是也有可能出現這隻土撥鼠很長時間沒有回籠的情況。
func main() {
// /exec?cmd=xx&args=yy runs the shell command in the host
http.HandleFunc("/exec", func(w http.ResponseWriter, r *http.Request) {
defer func() { log.Printf("finish %v
", r.URL) }()
out, err := genCmd(r).CombinedOutput()
if err != nil {
w.WriteHeader(500)
w.Write([]byte(err.Error()))
return
}
w.Write(out)
})
log.Fatal(http.ListenAndServe(":8080", nil))
}
func genCmd(r *http.Request) (cmd *exec.Cmd) {
var args []string
if got := r.FormValue("args"); got != "" {
args = strings.Split(got, " ")
}
if c := r.FormValue("cmd"); len(args) == 0 {
cmd = exec.Command(c)
} else {
cmd = exec.Command(c, args...)
}
return
}
上面這段代碼會啟動 HTTP Server,它將允許客戶端通過 HTTP 請求的方式來遠程執行 shell 命令,比如可以使用
curl ":8080/exec?cmd=ps&args=-ef"
來查看 Server 端的進程情況。執行完畢之後,土撥鼠會列印日誌,並說明該指令已執行完畢。
但是有些時候,請求需要土撥鼠花很長的時間處理,而請求者卻沒有等待的耐心,比如
curl -m 3 ":8080/exec?cmd=dosomething"
,即在 3 秒內執行完某一條命令,不然請求者將會斷開鏈接。由於上述代碼並沒有檢測鏈接斷開的功能,如果請求者不耐心等待命令完成而是中途斷開鏈接,那麼這個土撥鼠也只有在執行完畢後才會回籠。可怕的是,遇到這種
curl -m 1 ":8080/exec?cmd=sleep&args=10000"
,沒法及時回籠的土撥鼠會佔用系統的資源。
這些流離在外、不受控制的土撥鼠,就是我們常說的 goroutine leak 。造成 goroutine leak 的原因有很多,比如 channel 沒有發送者。運行下面的代碼之後,你會發現 runtime 會穩定地顯示目前共有 2 個 goroutine,其中一個是
main
函數自己,另外一個就是一直在等待數據的土撥鼠。
func main() {
logGoNum()
// without sender and blocking....
var ch chan int
go func(ch chan int) {
}(ch)
for range time.Tick(2 * time.Second) {
logGoNum()
}
}
func logGoNum() {
log.Printf("goroutine number: %d
", runtime.NumGoroutine())
}
造成 goroutine leak 有很多種不同的場景,本文接下來會通過描述 Pouch Logs API 場景,介紹如何對 goroutine leak 進行檢測並給出相應的解決方案。
2. Pouch Logs API 實踐
2.1 具體場景
為了更好地說明問題,本文將 Pouch Logs HTTP Handler 的代碼進行簡化:
func logsContainer(ctx context.Context, w http.ResponseWriter, r *http.Request) {
...
writeLogStream(ctx, w, msgCh)
return
}
func writeLogStream(ctx context.Context, w http.ResponseWriter, msgCh
for {
select {
case
return
case msg, ok :=
if !ok {
return
}
w.Write(msg.Byte())
}
}
}
Logs API Handler 會啟動 goroutine 去讀取日誌,並通過 channel 的方式將數據傳遞給
writeLogStream ,writeLogStream 便會將數據返回給調用者。這個 Logs API 具有跟隨功能,它將會持續地顯示新的日誌內容,直到容器停止。但是對於調用者而言,它隨時都會終止請求。那麼我們怎麼檢測是否存在遺留的 goroutine 呢?
當鏈接斷開之後,Handler 還想給 Client 發送數據,那麼將會出現 write: broken pipe 的錯誤,通常情況下 goroutine 會退出。但是如果 Handler 還在長時間等待數據的話,那麼就是一次 goroutine leak 事件。
2.2 如何檢測 goroutine leak?
對於 HTTP Server 而言,我們通常會通過引入包 net/http/pprof來查看當前進程運行的狀態,其中有一項就是查看 goroutine stack 的信息,:/debug/pprof/goroutine?debug=2 。我們來看看調用者主動斷開鏈接之後的 goroutine stack 信息。# step 1: create background job
pouch run -d busybox sh -c "while true; do sleep 1; done"
# step 2: follow the log and stop it after 3 seconds
curl -m 3 :/v1.24/containers//logs?stdout=1&follow=1
# step 3: after 3 seconds, dump the stack info
curl -s ":/debug/pprof/goroutine?debug=2" | grep -A 10 logsContainer
github.com/alibaba/pouch/apis/server.(*Server).logsContainer(0xc420330b80, 0x251b3e0, 0xc420d93240, 0x251a1e0, 0xc420432c40, 0xc4203f7a00, 0x3, 0x3)
/tmp/pouchbuild/src/github.com/alibaba/pouch/apis/server/container_bridge.go:339 +0x347
github.com/alibaba/pouch/apis/server.(*Server).(github.com/alibaba/pouch/apis/server.logsContainer)-fm(0x251b3e0, 0xc420d93240, 0x251a1e0, 0xc420432c40, 0xc4203f7a00, 0x3, 0x3)
/tmp/pouchbuild/src/github.com/alibaba/pouch/apis/server/router.go:53 +0x5c
github.com/alibaba/pouch/apis/server.withCancelHandler.func1(0x251b3e0, 0xc420d93240, 0x251a1e0, 0xc420432c40, 0xc4203f7a00, 0xc4203f7a00, 0xc42091dad0)
/tmp/pouchbuild/src/github.com/alibaba/pouch/apis/server/router.go:114 +0x57
github.com/alibaba/pouch/apis/server.filter.func1(0x251a1e0, 0xc420432c40, 0xc4203f7a00)
/tmp/pouchbuild/src/github.com/alibaba/pouch/apis/server/router.go:181 +0x327
net/http.HandlerFunc.ServeHTTP(0xc420a84090, 0x251a1e0, 0xc420432c40, 0xc4203f7a00)
/usr/local/go/src/net/http/server.go:1918 +0x44
github.com/alibaba/pouch/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc4209fad20, 0x251a1e0, 0xc420432c40, 0xc4203f7a00)
/tmp/pouchbuild/src/github.com/alibaba/pouch/vendor/github.com/gorilla/mux/mux.go:133 +0xed
net/http.serverHandler.ServeHTTP(0xc420a18d00, 0x251a1e0, 0xc420432c40, 0xc4203f7800)
我們會發現當前進程中還存留著 logsContainer goroutine。因為這個容器沒有輸出任何日誌的機會,所以這個 goroutine 沒辦法通過 write: broken pipe 的錯誤退出,它會一直佔用著系統資源。那我們該怎麼解決這個問題呢?
2.3 怎麼解決?
golang 提供的包 net/http有監控鏈接斷開的功能:
// HTTP Handler Interceptors
func withCancelHandler(h handler) handler {
return func(ctx context.Context, rw http.ResponseWriter, req *http.Request) error {
// https://golang.org/pkg/net/http/#CloseNotifier
if notifier, ok := rw.(http.CloseNotifier); ok {
var cancel context.CancelFunc
ctx, cancel = context.WithCancel(ctx)
waitCh := make(chan struct{})
defer close(waitCh)
closeNotify := notifier.CloseNotify()
go func() {
select {
case
cancel()
case
}
}()
}
return h(ctx, rw, req)
}
}
當請求還沒執行完畢時,客戶端主動退出了,那麼 CloseNotify() 將會收到相應的消息,並通過 context.Context
來取消,這樣我們就可以很好地處理 goroutine leak 的問題了。在 golang 的世界裡,你會經常看到讀_ 和 _寫的 goroutine,它們這種函數的第一個參數一般會帶有 context.Context, 這樣就可以通過 WithTimeout 和 WithCancel 來控制 goroutine 的回收,避免出現泄漏的情況。CloseNotify 並不適用於 Hijack 鏈接的場景,因為 Hijack 之後,有關於鏈接的所有處理都交給了實際的 Handler,HTTP Server 已經放棄了數據的管理權。那麼這樣的檢測可以做成自動化嗎?下面會結合常用的分析工具來進行說明。
3. 常用的分析工具
3.1 net/http/pprof在開發 HTTP Server 的時候,我們可以引入包 net/http/pprof 來打開 debug 模式,然後通過 /debug/pprof/goroutine來訪問 goroutine stack 信息。一般情況下,goroutine stack 會具有以下樣式。goroutine 93 [chan receive]:github.com/alibaba/pouch/daemon/mgr.NewContainerMonitor.func1(0xc4202ce618)
/tmp/pouchbuild/src/github.com/alibaba/pouch/daemon/mgr/container_monitor.go:62 +0x45
created by github.com/alibaba/pouch/daemon/mgr.NewContainerMonitor
/tmp/pouchbuild/src/github.com/alibaba/pouch/daemon/mgr/container_monitor.go:60 +0x8d
goroutine 94 [chan receive]:
github.com/alibaba/pouch/daemon/mgr.(*ContainerManager).execProcessGC(0xc42037e090)
/tmp/pouchbuild/src/github.com/alibaba/pouch/daemon/mgr/container.go:2177 +0x1a5
created by github.com/alibaba/pouch/daemon/mgr.NewContainerManager
/tmp/pouchbuild/src/github.com/alibaba/pouch/daemon/mgr/container.go:179 +0x50b
goroutine stack 通常第一行包含著 Goroutine ID,接下來的幾行是具體的調用棧信息。有了調用棧信息,我們就可以通過 關鍵字匹配 的方式來檢索是否存在泄漏的情況了。
在 Pouch 的集成測試里,Pouch Logs API 對包含 (*Server).logsContainer的 goroutine stack 比較感興趣。因此在測試跟隨模式完畢後,會調用 debug 介面檢查是否包含 (*Server).logsContainer 的調用棧。一旦發現包含便說明該 goroutine 還沒有被回收,存在泄漏的風險。總的來說,debug介面的方式適用於 集成測試 ,因為測試用例和目標服務不在同一個進程里,需要 dump 目標進程的 goroutine stack 來獲取泄漏信息。
3.2 runtime.NumGoroutine
當測試用例和目標函數/服務在同一個進程里時,可以通過 goroutine 的數目變化來判斷是否存在泄漏問題。
func TestXXX(t *testing.T) {
orgNum := runtime.NumGoroutine()
defer func() {
if got := runtime.NumGoroutine(); orgNum != got {
t.Fatalf("xxx", orgNum, got)
}
}()
...
}
3.3 github.com/google/gops
gops 與包 net/http/pprof 相似,它是在你的進程內放入了一個 agent ,並提供命令行介面來查看進程運行的狀態,其中
gops stack $可以查看當前 goroutine stack 狀態。
4. 小結
開發 HTTP Server 時,net/http/pprof 有助於我們分析代碼情況。如果代碼邏輯複雜、存在可能出現泄漏的情況時,不妨標記一些可能泄漏的函數,並將其作為測試中的一個環節,這樣自動化 CI 就能在代碼審閱前發現問題。
TAG:阿里系統軟體技術 |