Open5

【Go lang】runtime.Stack使ってみたゴール―チンの挙動を追ってみた

eisukeeisuke

runtime.Stackでは何ができる?

StartTrace enables tracing for the current process. While tracing, the data will be buffered and available via ReadTrace. StartTrace returns an error if tracing is already enabled. Most clients should use the runtime/trace package or the testing package's -test.trace flag instead of calling StartTrace directly.

StartTrace は、現在のプロセスのトレースを有効にします。トレース中、データはバッファリングされ、ReadTrace 経由で利用可能になります。トレースがすでに有効になっている場合、StartTrace はエラーを返します。ほとんどのクライアントは、StartTrace を直接呼び出すのではなく、ランタイム/トレース パッケージまたはテスト パッケージの -test.trace フラグを使用する必要があります。

スタックトレースからとれる情報を出力してみる

func main() {
	// 監視対象のgoroutine
	go func() {
		for {
			time.Sleep(1 * time.Second)
		}
	}()

	// スタックトレースの監視場所(以下からツールになる予定)
	buf := make([]byte, 1024)
	for {
		// すべてのゴルーチンのスタックトレースを取得
		// falseにすると現在動いているgoroutineしかとらないようにすることができる
		n := runtime.Stack(buf, true)
		// bufの中からスタックトレースが書き込まれた部分を表示される
		fmt.Printf("< Stack trace >\n%s\n", buf[:n])
		time.Sleep(2 * time.Second)
	}
}

n := runtime.Stack(buf, true) ここでは書き込まれたバイト数が返されている。
該当コード

// Stack formats a stack trace of the calling goroutine into buf
// and returns the number of bytes written to buf.
// If all is true, Stack formats stack traces of all other goroutines
// into buf after the trace for the current goroutine.
func Stack(buf []byte, all bool) int {
	if all {
		stopTheWorld("stack trace")
	}

何が書き込まれているのか表示させるにはbufスライスから先ほど返ってきたバイトの部分を指定する。

        fmt.Printf("< Stack trace >\n%s\n", buf[:n])
eisukeeisuke

go1.21rc1版だと以下の結果が返ってくる。

> go1.21rc1 run main.go
=== Stack trace ===
goroutine 1 [running]:
main.main()
        D:/Samples/EnablementInternship0622/src/main.go:18 +0xb5

goroutine 6 [sleep]:
time.Sleep(0x3b9aca00)
        C:/Users/Keisu/sdk/go1.21rc1/src/runtime/time.go:195 +0x126
main.main.func1()
        D:/Samples/EnablementInternship0622/src/main.go:12 +0x18
created by main.main in goroutine 1 <---[親goroutineIDも返ってきている]
        D:/Samples/EnablementInternship0622/src/main.go:10 +0x1e

あとはこれらのIDを配列に格納していく感じで。

eisukeeisuke

必要な情報

  • 時間
  • ゴール―チンID
  • ゴール―チンの状態(どのような状態があるか確認:running,runnable,sleepまで確認できた。)
  • 親ルーチンID(親があれば)

取り合えずbuf[:n]から先ほどの情報をパースして配列などにまとめていく。

まとめた情報をどのようにビジュアライズしていくか確認。

eisukeeisuke

チャンネルの受け取り送信のStatusがとれるようになった

チャンネル送信されたときに出力されるもの

goroutine 6 [chan send]:
...

パースする際の型

	common := regexp.MustCompile(`goroutine (\d+) \[(.+)\]:`)

出力結果

Goroutine ID: 8, Status: sleep, Parent ID: 1
Goroutine ID: 1, Status: running, Parent ID: 
Goroutine ID: 6, Status: chan send, Parent ID: 1
Goroutine ID: 7, Status: chan send, Parent ID: 1
Goroutine ID: 8, Status: chan send, Parent ID: 1
Goroutine ID: 1, Status: running, Parent ID: 
Goroutine ID: 6, Status: chan send, Parent ID: 1
Goroutine ID: 7, Status: chan send, Parent ID: 1
Goroutine ID: 8, Status: chan send, Parent ID: 1

全体コード

func parseGoroutines(stack string) []Goroutine {
	common := regexp.MustCompile(`goroutine (\d+) \[(.+)\]:`)
	child := regexp.MustCompile(`created by .+ in goroutine (\d+)`)

	lines := strings.Split(stack, "\n")
	var goroutines []Goroutine
	var lastGoroutine *Goroutine

	for _, line := range lines {
		if match := common.FindStringSubmatch(line); match != nil {
			g := Goroutine{
				ID:     match[1],
				Status: match[2],
			}
			goroutines = append(goroutines, g)
			lastGoroutine = &goroutines[len(goroutines)-1]
		} else if match := child.FindStringSubmatch(line); match != nil && lastGoroutine != nil {
			lastGoroutine.ParentID = match[1]
		}
	}

	return goroutines
}
eisukeeisuke

dotファイルにいい感じに出力したい

  • chan sendの場合親ルーチンに向かって赤やじるし
  • chan receiveの場合親ルーチンから子に向かって青やじるし