goメモリ漏洩case

4220 ワード

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を使っていないので、バグは見つかりませんでした.次に、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 yields
gc782(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 yields
gc783(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

gc 781:プログラム起動から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:パラレルタグフェーズの効率を説明します.他のスレッドを待つ間、yields操作は全部で0回行われます.
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は、すべての割り当てられたオブジェクト(ゴミオブジェクトを含む)を表示できます.しかし、この2つの方法では異常は発見されなかった.
(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が正常に終了していないことが判明した後、ビューコードを再確認し、漏洩の根本的な原因を発見した.再構成前に、信号処理プログラムでは、正常にプログラムを終了するために、goroutineごとにchannelがあり、メインgoroutineがすべてのgoroutineが正常に終了してから終了するのを待つために使用される.メインgoroutineでは、信号処理プログラムはすべてのgoroutineのコードを待つために使用されます.
waiters = make([]chan int, Num)
for _, w := range waiters {
    

チェックロジックを実行するgoroutineは終了後agを呼び出す.w
再構築後、各ラウンドごとにgoroutineが作成するため、主goroutineと検査ロジックのgoroutineの間のchannelのサイズが1であるため、作成された検査goroutineはすべてagにブロックする.w
(5)まとめ
-goroutineの管理は重要です.goroutineが漏洩するとメモリが漏洩します.
-http serverを埋め込み、プログラムの実行状態を表示します.
-現在、goのgcはまだ脆弱で、オブジェクトの作成をできるだけ減らし、キャッシュできるものはキャッシュします.対象が多くなるとスキャン時間も長くなりますので