go記憶體泄露case

標籤：golang   gc   記憶體泄露   

用go寫了一個守護進程程式：用於檢測redis的存活狀態並將結果寫到zookeeper中，部署到redis機器上，對於每個redis執行個體會有一個goroutine每隔固定時間去檢測其狀態，由主goroutine負責訊號處理等，再接收到訊號時kill其他的goroutine。程式運行了一段時間發現，有些redis執行個體的對應zookeeper的資訊不更新，通過日誌發現對應redis的goroutine掛掉了。閱讀源碼發現貌似是zk的第三方庫拋出一個非預期的異常導致。

為瞭解決這個問題，對邏輯重構：由主goroutine每隔固定時間，對於每個redis執行個體啟動一個goroutine去進行檢測，避免出現非預期異常導致goroutine掛掉，從而狀態資訊不更新的情況。由於goroutine的建立開銷很低，並且golang官方推薦使用大量的goroutine來抗並發，所以這種方式實現也很合理。重構完，上線測試發現存在記憶體泄露。

（1）觀察GC

首先對代碼review，因為半年前寫的，並且最近都沒用golang，所以沒有發現bug。接著，就想看下gc相關的資訊，也許可能透漏些東西。網上查了golang gc相關，在runtime的doc中描述了，通過設定環境變數GODEBUG=‘gctrace=1‘可以讓go的運行時把gc資訊列印到stderr。

GODEBUG=‘gctrace=1‘ ./sentinel-agent >gc.log &

gc.log的輸出如下：

gc781(1): 1+2385+17891+0 us, 60 -> 60 MB, 21971 (3503906-3481935) objects, 13818/14/7369 sweeps, 0(0) handoff, 0(0) steal, 0/0/0 yieldsgc782(1): 1+1794+18570+1 us, 60 -> 60 MB, 21929 (3503906-3481977) objects, 13854/1/7315 sweeps, 0(0) handoff, 0(0) steal, 0/0/0 yieldsgc783(1): 1+1295+20499+0 us, 59 -> 59 MB, 21772 (3503906-3482134) objects, 13854/1/7326 sweeps, 0(0) handoff, 0(0) steal, 0/0/0 yields

gc781：從程式啟動開始，第781次gc

(1)：參與gc的線程個數

1+2385+17891+0：分別是1）stop-the-world的時間，即暫停所有goroutine；2）清掃標記對象的時間；3）標記垃圾對象的時間；4）等待線程結束的耗時。單位都是us，4者之和就是gc暫停整體耗時

60 -> 60 MB：gc後，堆上存活對象佔用的記憶體，以及整個堆大小（包括垃圾對象）

21971 (3503906-3481935) objects：gc後，堆上的對象數量，gc前分配的對象以及本次釋放的對象

13818/14/7369 sweeps：描述對象清掃階段。一共有13818個memory span，其中14在後台被清掃，7369在stop-the-world期間被清掃

0(0) handoff，0(0) steal：描述並行標記階段的負載平衡特性。當前在不同線程間傳送運算元和總傳送運算元，以及當前steal運算元和總steal運算元

0/0/0 yields：描述並行標記階段的效率。在等待其他線程的過程中，一共有0次yields操做

經過觀察gc的輸出，發現當前堆上對象總數不斷增多，沒有減少的趨勢，這說明存在對象的泄露，從而導致記憶體泄露。

（2）memory profile

根據golang官網profile指南，在代碼中添加

import _ "net/http/pprof"func main() {    go func() {        http.ListenAndServe("localhost:6060", nil)    }()}

可以在運行時對程式進行profile，通過http訪問：

go tool pprof http://localhost:6060/debug/pprof/heap

進行memory profile，預設是--inuse_space，顯示當前活躍的對象（不包括垃圾對象）佔用的空間。使用--alloc_space可以顯示所有分配的對象（包括垃圾對象）。不過這兩種方式都沒有發現異常。

（3）監控goroutine個數

通過runtime.NumGoroutine()可以擷取當前的goroutine的個數。通過給程式添加http server擷取一些統計資訊來瞭解程式的運行狀態，這是Jeff Dean推崇的方法。通過添加下述代碼來即時查看goroutine的個數

    // goroutine stats and pprof    go func() {        http.HandleFunc("/goroutines", func(w http.ResponseWriter, r *http.Request) {            num := strconv.FormatInt(int64(runtime.NumGoroutine()), 10)            w.Write([]byte(num))        });        http.ListenAndServe("localhost:6060", nil)        glog.Info("goroutine stats and pprof listen on 6060")    }()

通過命令：

curl localhost:6060/goroutines

查詢當前的goroutine的個數。通過不程式運行期間，不斷查看，發現goroutine個數不斷增加，沒有銷毀的跡象。

（4）goroutine泄露

通過上面的觀察，發現存在goroutine泄露，即goroutine沒有正常退出。由於每輪（每隔10秒執行一次）都會建立多個goroutine，如果不能正常退出，則會存在大量的goroutine。go的gc使用的是mark and sweep，會從全域變數、goroutine的棧為根集合掃描所有的存活對象，如果goroutine不退出，就會泄露大量記憶體。

在確定是由於goroutine沒有正常退出後，重新review代碼，發現了泄露的根本原因。在重構前，在訊號處理常式中，為了正常結束程式，對於每個goroutine都有一個channel，用於主goroutine等待所有goroutine正常結束後再退出。主goroutine中，訊號處理常式用於等待所有goroutine的代碼：

waiters = make([]chan int, Num)for _, w := range waiters {    <- w}

執行檢查邏輯的goroutine在結束後，會調用ag.w <- 1，用於向主goroutine發送訊息。

重構後，由於每輪都會建立goroutine，由於用於主goroutine和檢查邏輯的goroutine之間的channel的大小是1，所以所有建立的檢查goroutine都阻塞在ag.w <- 1上，不能正常退出。最後，把channel邏輯去掉，就不存在goroutine泄露了。

（5）總結

- goroutine的管理很重要，如果goroutine泄露，就會存在記憶體泄露

- 內嵌http server，用於查看程式運行狀態

- 目前，go的gc還比較脆弱，盡量減少對象的建立，能緩衝的就緩衝。因為對象多了的話，掃描的時間也會加長

著作權聲明：本文為博主原創文章，未經博主允許不得轉載。

go記憶體泄露case