GOTRACEBACK を使用して Panic を迅速に特定する

最近、Go のプロジェクトを K8s マシンに移行したところ、マシンが時々自動的に再起動することがわかりました。再起動前のログを確認しようとしたところ、Goroutine の実行状態がすべて出力されましたが、会社のクラウドプラットフォームでは行数制限があるため、最後まで見ても、必要な panic の重要なスタック情報は得られませんでした。

初期段階では、頻繁な再起動のため、どこかで未捕捉の panic が発生しているのではないかと疑い、使用しているサードパーティパッケージの RocketMQ や Talos などの SDK パッケージで、プロデュースとコンシュームの初期化時に recover を追加し、プロジェクト内の channel の重要な操作にも recover を追加しましたが、問題は解決せず、再起動が時々発生しました。

Go の公式ドキュメントを調べてみると、環境変数 GOTRACEBACK を設定することで、panic が発生した後のスタックトレースの出力レベルを制御できることがわかりました。

GOTRACEBACK#

Go ランタイムは、この環境変数を使用して、プログラムがクラッシュしたり、未処理の panic が発生したときに、どの程度のスタックトレース情報を出力するかを決定します。これは、Go プログラムを実行する際に環境変数を介して Go ランタイムに渡されます。

none プログラムがクラッシュしたとき、スタック情報を出力しません；
single クラッシュを引き起こした panic の goroutine のスタック情報のみを表示します；
all すべての goroutine のスタック情報を表示します；
system すべての goroutine のスタック情報を表示し、ランタイム内部の goroutine の情報も含みます；
crash すべての goroutine のスタック情報を表示した後、コアダンププログラムを実行して終了します；

runtime package - runtime - Go Packages

ソースコード#

Go 1.20 バージョンに基づいています

GOTRACEBACK の設定#

//go:linkname setTraceback runtime/debug.SetTraceback  
func setTraceback(level string) {  
    var t uint32  
    switch level {  
    case "none":  
       t = 0  
    case "single", "":  
       t = 1 << tracebackShift  
    case "all":  
       t = 1<<tracebackShift | tracebackAll  
    case "system":  
       t = 2<<tracebackShift | tracebackAll  
    case "crash":  
       t = 2<<tracebackShift | tracebackAll | tracebackCrash  
    default:  
       t = tracebackAll  
       if n, ok := atoi(level); ok && n == int(uint32(n)) {  
          t |= uint32(n) << tracebackShift  
       }  
    }  
    // Cがプロセスを所有している場合、致命的なエラーやpanicが発生したときに単にプロセスを終了するのは驚くべきことです。  
    // より大きな音で中止します。    if islibrary || isarchive {  
       t |= tracebackCrash  
    }  
  
    t |= traceback_env  
  
    atomic.Store(&traceback_cache, t)  
}

GOTRACEBACK の取得#

// gotracebackは現在のtraceback設定を返します。//  
// levelが0の場合、すべてのトレースバックを抑制します。  
// levelが1の場合、トレースバックを表示しますが、ランタイムフレームは除外します。  
// levelが2の場合、ランタイムフレームを含むトレースバックを表示します。  
// allが設定されている場合、すべてのgoroutineスタックを印刷します。そうでない場合は、現在のgoroutineのみを印刷します。  
// crashが設定されている場合、トレースバック後にクラッシュします（コアダンプなど）。//  
//go:nosplit  
func gotraceback() (level int32, all, crash bool) {  
    gp := getg()  
    t := atomic.Load(&traceback_cache)  
    crash = t&tracebackCrash != 0  
    all = gp.m.throwing >= throwTypeUser || t&tracebackAll != 0  
    if gp.m.traceback != 0 {  
       level = int32(gp.m.traceback)  
    } else if gp.m.throwing >= throwTypeRuntime {  
       // m.tracebackによって上書きされない限り、ランタイムスローでは常にランタイムフレームを含めます。       level = 2  
    } else {  
       level = int32(t >> tracebackShift)  
    }  
    return  
}

GOTRACEBACK に基づくスタック情報の印刷#

// gpはこのM上でクラッシュしているgですが、ユーザーGである可能性もあり、getg()は  
// 常にg0です。  
func dopanic_m(gp *g, pc, sp uintptr) bool {  
    if gp.sig != 0 {  
       signame := signame(gp.sig)  
       if signame != "" {  
          print("[signal ", signame)  
       } else {  
          print("[signal ", hex(gp.sig))  
       }  
       print(" code=", hex(gp.sigcode0), " addr=", hex(gp.sigcode1), " pc=", hex(gp.sigpc), "]\n")  
    }  
  
    level, all, docrash := gotraceback()  
    if level > 0 {  
       if gp != gp.m.curg {  
          all = true  
       }  
       if gp != gp.m.g0 {  
          print("\n")  
          goroutineheader(gp)  
          traceback(pc, sp, 0, gp)  
       } else if level >= 2 || gp.m.throwing >= throwTypeRuntime {  
          print("\nruntime stack:\n")  
          traceback(pc, sp, 0, gp)  
       }  
       if !didothers && all {  
          didothers = true  
          tracebackothers(gp)  
       }  
    }  
    unlock(&paniclk)  
  
    if panicking.Add(-1) != 0 {  
       // 他のmもpanicしています。  
       // 必要なものを印刷させてください。       // CPUを消費せずに永遠に待ちます。       // 完了すると終了します。       lock(&deadlock)  
       lock(&deadlock)  
    }  
  
    printDebugLog()  
  
    return docrash  
}

テスト#

package main  
  
import (  
    "fmt"  
    "os"    "time")  
  
func main() {  
  
    env := os.Getenv("GOTRACEBACK")  
    fmt.Printf("GOTRACEBACK: %s\n", env)  
  
    for i := 0; i < 3; i++ {  
       go a()  
    }  
    go b()  
    for i := 0; i < 3; i++ {  
       go a()  
    }  
  
    time.Sleep(time.Second * 1)  
}  
  
func a() {  
    time.Sleep(time.Millisecond * 1)  
    fmt.Printf("aaaaaaa\n")  
}  
  
func b() {  
    time.Sleep(time.Millisecond * 1)  
    panic("b panic ......")  
}