# Go Perf Execution Tracer

> Owns the Go execution tracer AT DEPTH — runtime/trace (Start/Stop, WithRegion, NewTask, Log), collecting via go test -trace, the net/http/pprof /debug/pprof/trace?seconds=N endpoint, and reading go tool trace (the timeline, goroutine analysis, scheduler-latency / syscall / network / synchronization blocking profiles, GC events, minimum mutator utilization). Covers user regions/tasks/logs for app-level latency, the post-1.21 low-overhead (1–2%) tracer, and the Go 1.25 trace.FlightRecorder ring buffer for capturing the seconds BEFORE a spike. Auto-invokes on "why is this slow sometimes", "trace this", "poor parallelism", "scheduler latency", "goroutines blocked on a channel", "capture a trace before the spike", "what is the runtime doing". The tracer is for latency / parallelism / scheduling / GC, NOT hot-spot hunting — route CPU/heap hot spots to go-perf-pprof-profiling.

- Skill: `ctoth/go-perf-execution-tracer` (Agent Skill, multi-file: 3 files)
- Install (CLI): `npx skillmds@latest add ctoth/go-perf-execution-tracer`
- Raw SKILL.md: https://api.skillmd.com/api/skills/ctoth/go-perf-execution-tracer/raw
- Safety review: pending
- Works with: Claude Code, Claude.ai, OpenAI Codex
- Category: Coding & Dev Tools
- Author: ctoth (https://skillmd.com/u/ctoth)
- Updated: 2026-09-17
- Page: https://skillmd.com/skills/ctoth/go-perf-execution-tracer

---


# Go Execution Tracer

> "The magic of a trace is that it can easily reveal things about a program that are hard to see in other ways. … a concurrency bottleneck where lots of goroutines block on the same channel … in an execution trace, the *lack* of execution will show up with amazing clarity."
> — Michael Knyszek, [More powerful Go execution traces](https://go.dev/blog/execution-traces-2024)

The execution tracer answers a different question than a profiler. A CPU profile ranks *on-CPU* work; the tracer reconstructs the **timeline of what every goroutine, processor, and the runtime did**, so it sees the *off-CPU* gaps — blocked on a channel, parked behind a syscall, waiting for the scheduler, stalled in GC. Which diagnostic answers which question is **`go-perf-methodology`**'s tool-selection matrix; this skill owns the tracer end to end. All Go below builds clean under `gofmt`/`go vet` on Go 1.25/1.26.

---

## 1. The Tracer Is Not a Profiler — When to Reach for It

The tracer "captures a wide range of runtime events. Scheduling, syscall, garbage collections, heap size, and other events are collected by runtime and available for visualization by `go tool trace`" ([Diagnostics](https://go.dev/doc/diagnostics)). It records "goroutine creation/blocking/unblocking, syscall enter/exit/block, GC-related events, changes of heap size, processor start/stop, etc. A precise nanosecond-precision timestamp and a stack trace is captured for most events" ([runtime/trace](https://pkg.go.dev/runtime/trace)).

The decisive boundary — **the tracer is for latency, parallelism, scheduling, and GC behavior, not for hot spots**: "it is not great for identifying hot spots such as analyzing the cause of excessive memory or CPU usage. Use profiling tools instead first to address them" ([Diagnostics](https://go.dev/doc/diagnostics)). Reach for the tracer when:

- a request is slow **sometimes** and a CPU profile shows nothing (the time is spent *off* CPU);
- a parallel workload **won't scale** — cores sit idle while work waits;
- goroutines **pile up or block** on one channel / lock and you want to *see* the wait;
- you suspect **scheduler latency** (runnable→running delay) or **GC pauses / mark-assist** stealing time;
- you need **per-request latency breakdown** via user tasks/regions (§5).

Hot-spot hunting (where CPU/heap time goes) → **`go-perf-pprof-profiling`**. Contention *attribution* by lock → **`go-perf-block-mutex-profiles`**. GC *knob* tuning → **`go-perf-gc-tuning`**.

---

## 2. Collecting a Trace — Three Entry Points

**(a) In a benchmark or test** — the cheapest way to capture a bounded trace:

```sh
go test -bench=. -trace=trace.out   # or -trace alone for the test run
go tool trace trace.out             # opens the web UI on a local port
```

**(b) Programmatically** with `runtime/trace` — `Start` "enables tracing … the trace will be buffered and written to w"; `Stop` "only returns after all the writes for the trace have completed" ([runtime/trace](https://pkg.go.dev/runtime/trace)):

```go
f, err := os.Create("trace.out")
if err != nil {
	log.Fatal(err)
}
defer f.Close()

if err := trace.Start(f); err != nil {
	log.Fatal(err)
}
defer trace.Stop()
// ... the code whose timeline you want ...
```

**(c) From a live server** via `net/http/pprof` — import `_ "net/http/pprof"`, then pull a fixed window:

```sh
curl -o trace.out 'http://localhost:6060/debug/pprof/trace?seconds=5'
go tool trace trace.out
```

The `seconds=N` endpoint traces for N seconds and streams the result — the production way to grab a window without a code change. Treat that debug port as privileged: never expose `net/http/pprof` on a public listener (depth → **`go-perf-pprof-profiling`**).

---

## 3. Reading `go tool trace` — Which View Answers Which Question

`go tool trace trace.out` serves a local web UI ([cmd/trace](https://pkg.go.dev/cmd/trace)). The views, mapped to the question each answers:

| View | Answers |
|---|---|
| **Timeline / "View trace by proc"** | Per-P/per-goroutine execution over time — *where are the idle gaps?* Visualizes GC, STW, and goroutine state transitions. |
| **Goroutine analysis** | Per-goroutine-kind breakdown of time: execution vs **block (sync)**, **block (chan)**, **sched wait**, **syscall**, **GC**. The fastest path to "what is this goroutine waiting on." |
| **Scheduler latency profile** | runnable→running delay — scheduler saturation, the off-CPU wait a CPU profile can't see. |
| **Syscall / Network / Sync blocking profiles** | Aggregate time blocked in syscalls, on network I/O, on synchronization — pprof-style trees derived from the trace. |
| **Minimum mutator utilization (MMU)** | A curve of the *worst-case* fraction of CPU left to your code (the "mutator") over windows of increasing length — the rigorous read on whether GC is hurting tail latency. |
| **User-defined tasks / regions** | Latency distribution per task type and the regions inside each (§5). |

The trace viewer ("View trace") page "comes from the Chrome/Chromium project and is only actively tested on that browser" — the derived **profiles work on every browser** ([cmd/trace](https://pkg.go.dev/cmd/trace)). The reflex on opening a trace: go to **Goroutine analysis** first to see *what state* time is spent in, then the **timeline** to see *when* the gaps occur.

---

## 4. Deriving pprof Blocking Profiles From a Trace

The same trace yields four pprof-format blocking profiles without re-running anything — the trace *already contains* every block event ([cmd/trace](https://pkg.go.dev/cmd/trace)):

```sh
go tool trace -pprof=sched   trace.out > sched.pprof    # scheduler latency
go tool trace -pprof=syscall trace.out > syscall.pprof  # time blocked in syscalls
go tool trace -pprof=net     trace.out > net.pprof      # network blocking
go tool trace -pprof=sync    trace.out > sync.pprof     # synchronization blocking
go tool pprof sync.pprof                                # then top/list/web as usual
```

This is the bridge between the tracer's timeline and pprof's call-tree ranking: the **timeline tells you a stall exists and when**; these profiles tell you **which call stacks** account for the blocked time, with familiar `top`/`list` ergonomics. (This is *trace-derived* network/syscall/sched blocking; the rate-gated `block`/`mutex` profiles from `runtime.SetBlockProfileRate`/`SetMutexProfileFraction` are a different mechanism — **`go-perf-block-mutex-profiles`**.)

---

## 5. User Annotation — Regions, Tasks, Logs (App-Level Latency)

Raw runtime events show *how* goroutines ran but not *what they were doing in your domain*. Three `runtime/trace` APIs (all Go 1.11) overlay application structure onto the timeline ([runtime/trace](https://pkg.go.dev/runtime/trace)):

```go
func handleRequest(ctx context.Context, req *Request) {
	// A task spans a logical operation; tracer measures task latency as the
	// time between NewTask and Task.End, with a latency distribution per type.
	ctx, task := trace.NewTask(ctx, "handleRequest")
	defer task.End()

	// A region marks a code span within the calling goroutine. Region.End
	// must run on the same goroutine; regions must nest.
	defer trace.StartRegion(ctx, "decode").End()

	trace.Log(ctx, "userID", req.UserID) // a one-off keyed event on the timeline
	// ...
}
```

- `NewTask` "creates a task instance … The trace tool measures task latency as the time between task creation and when the End method is called, and provides the latency distribution per task type" ([runtime/trace](https://pkg.go.dev/runtime/trace)). A task can cross goroutines (carried in the `context`), so it captures an end-to-end request.
- `StartRegion`/`Region.End` (or the callback form `WithRegion`) mark a span "associated with its calling goroutine"; `End` "must be called from the same goroutine where the region was started. Within each goroutine, regions must nest" ([runtime/trace](https://pkg.go.dev/runtime/trace)). Use the `defer trace.StartRegion(ctx, "name").End()` idiom.
- `Log`/`Logf` "emits a one-off event with the given category and message"; keep categories to "a handful of unique" values ([runtime/trace](https://pkg.go.dev/runtime/trace)).

Keep `regionType`/`taskType`/`category` to a **bounded, small set of constant strings** — the analysis tools "may assume there are only a bounded number of unique task types" ([runtime/trace](https://pkg.go.dev/runtime/trace)). A high-cardinality label (a per-request ID as the *type*) defeats the per-type aggregation; put that in a `Log` value instead. Without these annotations the User-defined-tasks view is empty and the timeline is unreadable on a real service.

---

## 6. The Flight Recorder — Capture the Seconds *Before* the Problem (Go 1.25)

The classic bind: rare latency spikes are exactly what you can't trace, because you don't know *when* to start tracing, and tracing continuously to disk is too expensive. The **flight recorder** inverts this: it "continuously records the trace into an in-memory ring buffer," and "when a significant event occurs, a program can call `FlightRecorder.WriteTo` to snapshot the last few seconds of the trace to a file" ([Go 1.25 release notes](https://go.dev/doc/go1.25)). It is "like a scalpel cutting directly to the problem area" — you keep only the trace that *matters*, the window leading up to the anomaly ([Flight Recorder in Go 1.25](https://go.dev/blog/flight-recorder)).

**Version fact (verified):** `trace.FlightRecorder` landed in the **standard library `runtime/trace` in Go 1.25.0** ([runtime/trace](https://pkg.go.dev/runtime/trace), [Go 1.25 release notes](https://go.dev/doc/go1.25), [blog, 26 Sep 2025](https://go.dev/blog/flight-recorder)). Before 1.25 it was **experimental in `golang.org/x/exp/trace`** ([execution-traces-2024](https://go.dev/blog/execution-traces-2024)) — if you target ≤1.24, that is the import path, and the API differs.

```go
fr := trace.NewFlightRecorder(trace.FlightRecorderConfig{
	MinAge:   2 * time.Second, // retain ~this much window; set ~2x your event's time scale
	MaxBytes: 10 << 20,        // hint/cap on buffer size; ~a few MB/s, ~10 MB/s for a busy service
})
if err := fr.Start(); err != nil {
	log.Fatal(err)
}
defer fr.Stop()

// In a request path, snapshot once when an anomaly trips:
if fr.Enabled() && time.Since(start) > 100*time.Millisecond {
	go snapshotOnce(fr) // WriteTo a file; guard with sync.Once so one spike writes one trace
}
```

- `WriteTo` "snapshots the moving window tracked by the flight recorder"; "only one goroutine may execute WriteTo at a time" ([runtime/trace](https://pkg.go.dev/runtime/trace)). Open the resulting file with `go tool trace` exactly like any other trace.
- `MinAge` is "a lower bound on the age of an event in the … window"; `MaxBytes` "takes precedence over MinAge … Treat it as a hint" ([runtime/trace](https://pkg.go.dev/runtime/trace)). Set `MinAge` to roughly 2× the timescale of the event you're hunting ([blog](https://go.dev/blog/flight-recorder)).
- Constraint: "currently only one flight recorder may be active in the program," though it "is allowed to be concurrently active with a trace consumer using `trace.Start`" ([runtime/trace](https://pkg.go.dev/runtime/trace)).

This is the right tool the instant the symptom is "it spikes once an hour and I can never catch it." Tail-latency *methodology* (p99/p999, coordinated omission) → **`go-perf-tail-latency`**.

---

## 7. Overhead — Why Continuous Tracing Became Viable

Pre-1.21, tracing cost "somewhere between 10–20% CPU for many applications, which limits tracing to situational usage." Work on traceback efficiency "cut [it] dramatically, down to 1–2% for many applications," and trace **splitting** (the runtime can self-contained-split a trace at any time) "landed in Go 1.22 and is now generally available" ([execution-traces-2024](https://go.dev/blog/execution-traces-2024)). That low overhead plus splittability is precisely what made the flight recorder (§6) implementable. Practical consequence: a **bounded** trace (a few seconds via `seconds=N`, or a flight-recorder snapshot) is cheap; leaving **full** `trace.Start` running forever still writes the entire firehose to your `io.Writer` — use the windowed forms, not an always-on `trace.Start` (§10).

---

## 8. A Worked Reading — "Poor Parallelism"

A CPU-bound batch job pins one core while seven idle. CPU profile: "looks busy in `compute`." That's a dead end — the *idle* cores are the symptom, and idleness has no CPU samples. The trace reading:

1. `go test -bench=BatchProcess -trace=trace.out` → `go tool trace`.
2. **Goroutine analysis**: workers spend most time in **block (chan)**, not execution → they're starved, not slow.
3. **Timeline**: a single producer goroutine runs continuously while consumers sit idle between bursts → the producer is the serial bottleneck (Amdahl's serial fraction made visible).
4. Fix the fan-out / buffering, re-trace, confirm the idle gaps closed. The throughput *fix* (pool sizing, batching) → **`go-perf-worker-pools-throughput`**; scheduler internals → **`go-perf-goroutines-scheduler`**.

The point: the answer was in the **absence** of execution, which only the tracer renders.

---

## 9. Don't

- **Don't reach for the tracer to find a CPU/heap hot spot** — it "is not great for identifying hot spots … Use profiling tools instead first" ([Diagnostics](https://go.dev/doc/diagnostics)). Hot spots → **`go-perf-pprof-profiling`**.
- **Don't leave full `trace.Start` running continuously** — it writes the whole event firehose to your writer. For ongoing capture use the **flight recorder** ring buffer (§6) or a bounded `seconds=N` window.
- **Don't call `Region.End` on a different goroutine** than `StartRegion`, and don't let regions cross without nesting — `End` "must be called from the same goroutine … regions must nest" ([runtime/trace](https://pkg.go.dev/runtime/trace)).
- **Don't use high-cardinality task/region/category names** — the tools assume "a bounded number of unique task types"; per-request IDs belong in a `Log` *value*, not the type ([runtime/trace](https://pkg.go.dev/runtime/trace)).
- **Don't assume `trace.FlightRecorder` exists pre-1.25** — it's stdlib `runtime/trace` from **1.25.0**; on ≤1.24 it's experimental `golang.org/x/exp/trace` ([Go 1.25](https://go.dev/doc/go1.25), [execution-traces-2024](https://go.dev/blog/execution-traces-2024)).
- **Don't run a second flight recorder** — "currently only one flight recorder may be active in the program" ([runtime/trace](https://pkg.go.dev/runtime/trace)).
- **Don't trust the "View trace" page on a non-Chromium browser** — only the derived `-pprof` profiles are cross-browser ([cmd/trace](https://pkg.go.dev/cmd/trace)).
- **Don't collect a trace and a precise memory profile in the same run** — diagnostics interfere; "use tools in isolation" ([Diagnostics](https://go.dev/doc/diagnostics)).
- **Don't expose `/debug/pprof/trace` on a public port** — it's a privileged endpoint (safety → **`go-perf-pprof-profiling`**).

---

## 10. Routing to Related Skills

**This plugin (`go-perf-*` depth):**

- `go-perf-methodology` — the tool-selection matrix: tracer vs profiler vs block/mutex vs gctrace; *read first*.
- `go-perf-pprof-profiling` — CPU/heap hot-spot hunting, `net/http/pprof` safety, labels, differential profiling.
- `go-perf-block-mutex-profiles` — the rate-gated `block`/`mutex`/`goroutine` profiles (distinct from trace-derived blocking profiles).
- `go-perf-goroutines-scheduler` — GMP/work-stealing internals, `GODEBUG=schedtrace`, container-aware `GOMAXPROCS` (1.25).
- `go-perf-gc-tuning` — acting on GC events the trace reveals: `GOGC`/`GOMEMLIMIT`, pacer, allocation rate.
- `go-perf-tail-latency` — p99/p999, coordinated omission; the flight recorder is how you *capture* a tail incident.
- `go-perf-worker-pools-throughput` — fixing the poor-parallelism the trace exposes (sizing, batching, fan-out).

**Parent / sibling marketplace (`go-*` correctness):**

- `go-performance` — the measure-first overview; this skill is the tracer leaf under it.
- `go-concurrency-goroutines` — goroutine lifetime/leak *correctness* (the tracer shows the *cost/blocking*).
- `go-version-feature-map` — version floors: low-overhead tracer 1.21–1.22; flight recorder stdlib 1.25.

---

## 11. Reference Files

Tracer anti-patterns in LLM-generated Go, each wrong/right with citations:

[references/common-mistakes.md](references/common-mistakes.md)

Source provenance for every claim in this skill:

[references/sources.yaml](references/sources.yaml)