Goメモ-253 (go tool trace コマンドを使って実行トレースを見る)(runtime/trace)

概要
サンプル
参考情報

概要

以下自分用のメモです。よく忘れるのでメモメモ。。。

Goには標準で実行トレースを採取する機能がついています。pprofとかもあるのですが、手軽に扱えるのが runtime/trace さん。

これをトレースを取りたいプログラムの先頭で

trace.Start(os.Stderr)
defer trace.Stop()

とかすると、プログラムを実行したタイミングでトレースファイルが出力されます。

サンプル

以下のようなプログラムがあるとします。中身に意味はないです。ゴルーチンとネットワークI/Oを使いたいだけのサンプル。

// go tool trace のサンプルです.
//
// # REFERENCES
//   - https://youngstone89.medium.com/go-tools-trace-25e4c1c442ff
//   - https://budougumi0617.github.io/2020/12/04/goroutine_tuning_with_benchmark_benchstat_trace/
package main

import (
    "context"
    "fmt"
    "io"
    "net/http"
    "os"
    "runtime/trace"
    "time"

    "github.com/devlights/gomy/chans"
    "github.com/devlights/gomy/ctxs"
    "github.com/devlights/gomy/errs"
)

func main() {
    trace.Start(os.Stderr)
    defer trace.Stop()

    var (
        rootCtx  = context.Background()
        ctx, cxl = context.WithTimeout(rootCtx, 10*time.Second)
    )
    defer cxl()

    var (
        urls = []string{
            "https://devlights.hatenablog.com/",
            "https://github.com/devlights/try-golang",
            "https://github.com/devlights/gomy",
            "https://github.com/devlights/goxcel",
            "https://github.com/devlights/try-csharp",
            "https://github.com/devlights/try-python",
        }
        in     = chans.GeneratorContext(ctx, urls...)
        wCnt   = 3
        fanout = chans.FanOutContext(ctx, in, wCnt, func(url string) {
            var (
                resp = errs.Stderr(http.Get(url))
                buf  = errs.Stderr(io.ReadAll(resp.Body))
            )
            defer resp.Body.Close()

            fmt.Printf("%s [%dbytes]\n", url, len(buf))
        })
    )

    <-ctxs.WhenAll(ctx, fanout...).Done()
}

以下のような Taskfile.yml を用意。

version: "3"

tasks:
  run:
    cmds:
      - go run main.go 2> trace.out
  trace:
    cmds:
      - cmd: go tool trace trace.out
        ignore_error: true

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

gitpod /workspace/try-golang (master) $ task -d examples/singleapp/go_tool_trace/ run
task: [run] go run main.go 2> trace.out
https://devlights.hatenablog.com/ [60931bytes]
https://github.com/devlights/try-golang [214498bytes]
https://github.com/devlights/gomy [217772bytes]
https://github.com/devlights/try-csharp [196142bytes]
https://github.com/devlights/try-python [205351bytes]
https://github.com/devlights/goxcel [256712bytes]

実行すると、ディレクトリに trace.out ファイルが出力されます。

gitpod /workspace/try-golang (master) $ ls -l examples/singleapp/go_tool_trace/
total 68
-rw-r--r-- 1 gitpod gitpod  1236 Sep 15 07:39 main.go
-rw-r--r-- 1 gitpod gitpod   157 Sep 15 07:39 Taskfile.yml
-rw-r--r-- 1 gitpod gitpod 59279 Sep 15 07:49 trace.out

次に、このトレースファイルを go tool trace に食べさせます。

$ task -d examples/singleapp/go_tool_trace/ trace
task: [trace] go tool trace trace.out
2022/09/15 07:50:29 Parsing trace...
2022/09/15 07:50:29 Splitting trace...
2022/09/15 07:50:29 Opening browser. Trace viewer is listening on http://127.0.0.1:37527