いろいろ備忘録日記

主に .NET とか Go とか Flutter とか Python絡みのメモを公開しています。

Goメモ-179 (スタックトレースを取得するやり方メモ)

概要

よく忘れるので、ここにメモメモ。。。

たまにスタックトレースを取りたいときがあったりします。

Goだと debug.PrintStack() とか debug.Stack() とか何個かやり方があるので

ついでに以下にメモしておきます。

debug.PrintStack()

package stacktrace

import (
    "context"
    "runtime/debug"
    "time"

    "github.com/devlights/gomy/output"
)

// DebugPrintStack -- runtime/debug.PrintStack のサンプルです.
//
// REFERENCES
//   - https://pkg.go.dev/runtime/debug#PrintStack
//   - https://stackoverflow.com/questions/19094099/how-to-dump-goroutine-stacktraces
func DebugPrintStack() error {
    var (
        third = func(pCtx context.Context) context.Context {
            ctx, cxl := context.WithTimeout(pCtx, 100*time.Millisecond)
            defer cxl()

            // この処理が走っているgoroutineのスタックトレースを出力 (全部ではない)
            output.StderrHr()
            debug.PrintStack()

            <-ctx.Done()

            return ctx
        }
        second = func(pCtx context.Context) context.Context {
            ctx, cxl := context.WithCancel(pCtx)
            go func() {
                defer cxl()
                <-third(ctx).Done()
            }()

            return ctx
        }
        first = func(pCtx context.Context) context.Context {
            ctx, cxl := context.WithCancel(pCtx)
            go func() {
                defer cxl()
                <-second(ctx).Done()
            }()

            return ctx
        }
    )

    <-first(context.Background()).Done()

    return nil
}

実行すると以下のようになります。

gitpod /workspace/try-golang (master) $ make run
go run github.com/devlights/try-golang/cmd/trygolang -onetime -example ""

ENTER EXAMPLE NAME: stacktrace_debug_printstack

[Name] "stacktrace_debug_printstack"
-------------------------------------------------- 
goroutine 20 [running]:
runtime/debug.Stack()
        /home/gitpod/go/src/runtime/debug/stack.go:24 +0x65
runtime/debug.PrintStack()
        /home/gitpod/go/src/runtime/debug/stack.go:16 +0x19
github.com/devlights/try-golang/examples/basic/stacktrace.DebugPrintStack.func1({0xaedc18, 0xc0001bf9c0})
        /workspace/try-golang/examples/basic/stacktrace/debug_printstack.go:24 +0x8d
github.com/devlights/try-golang/examples/basic/stacktrace.DebugPrintStack.func2.1()
        /workspace/try-golang/examples/basic/stacktrace/debug_printstack.go:34 +0x47
created by github.com/devlights/try-golang/examples/basic/stacktrace.DebugPrintStack.func2
        /workspace/try-golang/examples/basic/stacktrace/debug_printstack.go:32 +0xc8


[Elapsed] 100.315646ms

C# とか Java やってる人からすると、Goのスタックトレースは逆になって出力されてるように見えるはずです。

debug.Stack()

package stacktrace

import (
    "context"
    "runtime/debug"
    "time"

    "github.com/devlights/gomy/output"
)

// DebugStack -- debug.Stack() の サンプルです。
//
// REFERENCES
//   - https://pkg.go.dev/runtime/debug#Stack
//   - https://stackoverflow.com/questions/19094099/how-to-dump-goroutine-stacktraces
func DebugStack() error {
    // channels
    var (
        ch = make(chan []byte, 1)
    )
    defer close(ch)

    // funcs
    var (
        third = func(pCtx context.Context) context.Context {
            ctx, cxl := context.WithTimeout(pCtx, 100*time.Millisecond)
            defer cxl()

            // この処理が走っているgoroutineのスタックトレースを取得 (全部ではない)
            ch <- debug.Stack()

            <-ctx.Done()

            return ctx
        }
        second = func(pCtx context.Context) context.Context {
            ctx, cxl := context.WithCancel(pCtx)
            go func() {
                defer cxl()
                <-third(ctx).Done()
            }()

            return ctx
        }
        first = func(pCtx context.Context) context.Context {
            ctx, cxl := context.WithCancel(pCtx)
            go func() {
                defer cxl()
                <-second(ctx).Done()
            }()

            return ctx
        }
    )

    // contexts
    var (
        ctx = first(context.Background())
    )

LOOP:
    for {
        select {
        case <-ctx.Done():
            break LOOP
        case buf := <-ch:
            output.Stdoutl("stack", string(buf))
        }
    }
    output.Stdoutl("done")

    return nil
}

実行すると以下のようになります。

gitpod /workspace/try-golang (master) $ make run
go run github.com/devlights/try-golang/cmd/trygolang -onetime -example ""

ENTER EXAMPLE NAME: stacktrace_debug_stack

[Name] "stacktrace_debug_stack"
stack                goroutine 20 [running]:
runtime/debug.Stack()
        /home/gitpod/go/src/runtime/debug/stack.go:24 +0x65
github.com/devlights/try-golang/examples/basic/stacktrace.DebugStack.func1({0xaedc18, 0xc00022f9c0})
        /workspace/try-golang/examples/basic/stacktrace/debug_stack.go:30 +0x68
github.com/devlights/try-golang/examples/basic/stacktrace.DebugStack.func2.1()
        /workspace/try-golang/examples/basic/stacktrace/debug_stack.go:40 +0x47
created by github.com/devlights/try-golang/examples/basic/stacktrace.DebugStack.func2
        /workspace/try-golang/examples/basic/stacktrace/debug_stack.go:38 +0xc8

done                 


[Elapsed] 100.320653ms

runtime.Stack()

debug.PrintStack() と debug.Stack() はどちらも内部で runtime.Stack() を呼び出しています。当然直接使うこともできます。

package stacktrace

import (
    "runtime"

    "github.com/devlights/gomy/output"
)

// RuntimeStack -- runtime.Stack() についてのサンプルです。
//
// REFERENCES
//   - https://pkg.go.dev/runtime#Stack
//   - https://stackoverflow.com/questions/19094099/how-to-dump-goroutine-stacktraces
func RuntimeStack() error {
    // channels
    var (
        chSingle = make(chan []byte, 1)
        chAll    = make(chan []byte, 1)
    )

    // funcs
    var (
        getStack = func(all bool) []byte {
            // From src/runtime/debug/stack.go
            var (
                buf = make([]byte, 1024)
            )

            for {
                n := runtime.Stack(buf, all)
                if n < len(buf) {
                    return buf[:n]
                }
                buf = make([]byte, 2*len(buf))
            }
        }
    )

    // runtime.Stack() の 第2引数 に false を渡すと、現在のgoroutineのみが対象
    go func(ch chan<- []byte) {
        defer close(ch)
        ch <- getStack(false)
    }(chSingle)

    // runtime.Stack() の 第2引数 に true  を渡すと、全てのgoroutineが対象
    go func(ch chan<- []byte) {
        defer close(ch)
        ch <- getStack(true)
    }(chAll)

    // runtime.Stack(false) の 結果
    for v := range chSingle {
        output.Stdoutl("=== stack-single", string(v))
    }

    // runtime.Stack(true) の 結果
    for v := range chAll {
        output.Stdoutl("=== stack-all   ", string(v))
    }

    return nil
}

実行すると以下のようになります。

gitpod /workspace/try-golang (master) $ make run
go run github.com/devlights/try-golang/cmd/trygolang -onetime -example ""

ENTER EXAMPLE NAME: stacktrace_runtime_stack

[Name] "stacktrace_runtime_stack"
=== stack-single     goroutine 21 [running]:
github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack.func1(0x0)
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:30 +0x6a
github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack.func2(0xc000112480)
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:42 +0x5f
created by github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:40 +0xd2

=== stack-all        goroutine 22 [running]:
github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack.func1(0x0)
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:30 +0x6a
github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack.func3(0xc0001124e0)
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:48 +0x62
created by github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:46 +0x152

goroutine 1 [runnable]:
github.com/devlights/try-golang/examples/basic/stacktrace.RuntimeStack()
        /workspace/try-golang/examples/basic/stacktrace/runtime_stack.go:52 +0x1f0
github.com/devlights/try-golang/runner.(*Exec).Run(0x4060105)
        /workspace/try-golang/runner/exec.go:52 +0x14c
github.com/devlights/try-golang/runner.(*Loop).exec(0xc0001580f0, {0xa18416, 0x18}, 0xc0001f8210)
        /workspace/try-golang/runner/loop.go:126 +0x8f
github.com/devlights/try-golang/runner.(*Loop).Run(0xc0001345b8)
        /workspace/try-golang/runner/loop.go:79 +0x265
main.main()
        /workspace/try-golang/cmd/trygolang/main.go:67 +0x532



[Elapsed] 379.428µs

pprof.Lookup("goroutine").WriteTo()

これが一番フレキシブルにいろいろな情報が取れるので便利です。

package stacktrace

import (
    "bytes"
    "fmt"
    "io"
    "runtime/pprof"

    "github.com/devlights/gomy/output"
)

// PprofGoroutineWriteTo -- pprof.Lookup("goroutine").WriteTo() のサンプルです.
// REFERENCES
//   - https://pkg.go.dev/runtime/pprof#Lookup
//   - https://pkg.go.dev/runtime/pprof#Profile.WriteTo
//   - https://pkg.go.dev/runtime/pprof#Profile
//   - https://stackoverflow.com/questions/19094099/how-to-dump-goroutine-stacktraces
func PprofGoroutineWriteTo() error {
    const (
        profile           = "goroutine" // https://pkg.go.dev/runtime/pprof#Profile に事前定義プロファイルが記載されている
        useGoroutineStyle = 2           // goroutineの場合 2 を指定すると debug.Stack() と同じフォーマットになる.
    )

    var (
        errCh = make(chan error, 1)
        buf   = bytes.NewBuffer(nil)
        fn    = func(w io.Writer) error {
            p := pprof.Lookup(profile)
            if p == nil {
                return fmt.Errorf("profile does not exists (%s)", profile)
            }

            return p.WriteTo(w, useGoroutineStyle)
        }
    )

    go func() {
        defer close(errCh)
        if err := fn(buf); err != nil {
            errCh <- err
        }
    }()

    for e := range errCh {
        return e
    }

    output.Stdoutl("pprof", buf.String())

    return nil
}

実行すると以下のようになります。

gitpod /workspace/try-golang (master) $ make run
go run github.com/devlights/try-golang/cmd/trygolang -onetime -example ""

ENTER EXAMPLE NAME: stacktrace_pprof_writeto

[Name] "stacktrace_pprof_writeto"
pprof                goroutine 6 [running]:
runtime/pprof.writeGoroutineStacks({0xade4c0, 0xc0001e6240})
        /home/gitpod/go/src/runtime/pprof/pprof.go:693 +0x70
runtime/pprof.writeGoroutine({0xade4c0, 0xc0001e6240}, 0xedd080)
        /home/gitpod/go/src/runtime/pprof/pprof.go:682 +0x2b
runtime/pprof.(*Profile).WriteTo(0xa09359, {0xade4c0, 0xc0001e6240}, 0x0)
        /home/gitpod/go/src/runtime/pprof/pprof.go:331 +0x14b
github.com/devlights/try-golang/examples/basic/stacktrace.PprofGoroutineWriteTo.func1({0xade4c0, 0xc0001e6240})
        /workspace/try-golang/examples/basic/stacktrace/pprof_goroutine_writeto.go:33 +0x4c
github.com/devlights/try-golang/examples/basic/stacktrace.PprofGoroutineWriteTo.func2()
        /workspace/try-golang/examples/basic/stacktrace/pprof_goroutine_writeto.go:39 +0x6f
created by github.com/devlights/try-golang/examples/basic/stacktrace.PprofGoroutineWriteTo
        /workspace/try-golang/examples/basic/stacktrace/pprof_goroutine_writeto.go:37 +0xb6

goroutine 1 [chan receive]:
github.com/devlights/try-golang/examples/basic/stacktrace.PprofGoroutineWriteTo()
        /workspace/try-golang/examples/basic/stacktrace/pprof_goroutine_writeto.go:44 +0xcb
github.com/devlights/try-golang/runner.(*Exec).Run(0x7060102)
        /workspace/try-golang/runner/exec.go:52 +0x14c
github.com/devlights/try-golang/runner.(*Loop).exec(0xc00002e210, {0xa183fe, 0x18}, 0xc0001e6210)
        /workspace/try-golang/runner/loop.go:126 +0x8f
github.com/devlights/try-golang/runner.(*Loop).Run(0xc0000105c8)
        /workspace/try-golang/runner/loop.go:79 +0x265
main.main()
        /workspace/try-golang/cmd/trygolang/main.go:67 +0x532



[Elapsed] 262.114µs

参考情報

stackoverflow.com


過去の記事については、以下のページからご参照下さい。

サンプルコードは、以下の場所で公開しています。