Go's Execution Tracer: A Ring Buffer of Events Per Goroutine

TL;DR: A CPU profile is a sample of where the CPU was. The execution tracer is a log of what happened: every goroutine creation, every scheduler switch, every channel block, every syscall and every GC phase is recorded as a typed event with a timestamp and a stack. The runtime batches those events into per-M buffers, deduplicates stacks and strings through lock-free hash tries, and hands them to a reader goroutine that writes a versioned trace file that go tool trace renders as a timeline.

If you have ever run go tool trace and watched a waterfall appear, you have seen something quite different from a CPU profile. The profile is a statistical sample; the trace is a history. Everything that happened is in there, in order, with timestamps.

The machinery behind that history is a ring of typed events, and this post is about how it works, based on the Go 1.28 development tree.

What makes it different from pprof

	CPU profile	Execution trace
Trigger	`SIGPROF` at 100 Hz	every interesting runtime event
Granularity	one stack per sample	every transition
Data	PCs per sample	typed events with args
Cost	~0 (statistical)	a few percent (real work)
Question answered	“what is hot?”	“what happened, and why?”

The key word in that last row is why. A profile can tell you that 40% of your CPU went into regexp.MatchString. It cannot tell you that most of that time was spent in one goroutine that was blocked 90% of the way through. Only a timeline can.

Starting a trace

The public API is two functions:

go
// src/runtime/trace/trace.go:115
// Start enables tracing for the current program.
// While tracing, the trace will be buffered and written to w.
// Start returns an error if tracing is already enabled.
func Start(w io.Writer) error {
	return tracing.subscribeTraceStartWriter(w)
}

// Stop stops the current tracing, if any.
// Stop only returns after all the writes for the trace have completed.
func Stop() {
	tracing.unsubscribeTraceStartWriter()
}

In Go 1.28 the runtime/trace package is a multiplexer: a traceStartWriter (the file you passed to Start) and a FlightRecorder (a rolling in-memory recorder) can both be attached to the same trace. The package keeps a subscriber count, and the underlying runtime trace is started when the first subscriber arrives and stopped when the last one leaves.

The interesting part is the goroutine that actually drains the trace:

go
// src/runtime/trace/subscribe.go:157
	go func() {
		header := runtime.ReadTrace()
		if traceStartWriter != nil {
			traceStartWriter.Write(header)
		}
		if flightRecorder != nil {
			flightRecorder.Write(header)
		}

		for {
			data := runtime.ReadTrace()
			if data == nil {
				break
			}
			if traceStartWriter != nil {
				traceStartWriter.Write(data)
			}
			if flightRecorder != nil {
				flightRecorder.Write(data)
			}
			if len(data) == 1 && tracev2.EventType(data[0]) == tracev2.EvEndOfGeneration {
				if flightRecorder != nil {
					flightRecorder.endGeneration()
				}

The runtime produces a byte stream; this goroutine copies it to the writer(s). Everything the tracer does is designed so that this loop never blocks the program: the runtime hands off full buffers and the reader picks them up.

The overall shape

text
   your goroutines
        |
        |  traceAcquire() / traceRelease()
        v
  +---------------------------------------------+
  |  per-M trace buffers (traceBuf)             |   <- written by the M,
  |  mp.trace.buf[gen%2][experiment]            |      no locks, no allocation
  +---------------------------------------------+
        |  full buffer -> trace.full[gen%2]
        v
  +---------------------------------------------+
  |  trace.full[gen%2]  (queue of full buffers) |
  +---------------------------------------------+
        |  ReadTrace()
        v
  +---------------------------------------------+
  |  reader goroutine -> your io.Writer         |
  +---------------------------------------------+

The runtime keeps a global trace state, and the buffer management is the first thing in it:

go
// src/runtime/trace.go:198
	// Trace buffer management.
	//
	// First we check the empty list for any free buffers. If not, buffers
	// are allocated directly from the OS. Once they're filled up and/or
	// flushed, they end up on the full queue for trace.gen%2.
	//
	// The trace reader takes buffers off the full list one-by-one and
	// places them into reading until they're finished being read from.
	// Then they're placed onto the empty list.
	//
	// Protected by trace.lock.
	reading       *traceBuf // buffer currently handed off to user
	empty         *traceBuf // stack of empty buffers
	full          [2]traceBufQueue
	workAvailable atomic.Bool

gen%2 is the trick that keeps this cheap. There are two sets of buffers, one for the current generation and one for the next, so the reader can be draining generation N while the program is already writing generation N+1. The generations are the tracer’s unit of “everything that happened between two stop-the-worlds”.

Per-M buffers, not per-goroutine buffers

An older description of the tracer — one you will still find in blog posts — says the runtime keeps a buffer of events per goroutine. That was true of the version 1 trace format. The modern tracer, the one behind the version 2 format, writes into per-M buffers:

go
// src/runtime/traceruntime.go:26
// mTraceState is per-M state for the tracer.
type mTraceState struct {
	writing       atomic.Bool                          // flag indicating that this M is writing to a trace buffer.
	buf           [2][tracev2.NumExperiments]*traceBuf // Per-M traceBuf for writing. Indexed by trace.gen%2.
	link          *m                                   // Snapshot of alllink or freelink.
	reentered     uint32                               // Whether we've reentered tracing from within tracing.
	entryGen      uintptr                              // The generation value on first entry.
	oldthrowsplit bool                                 // gp.throwsplit upon calling traceLocker.writer. For debugging.
}

That is a better design than per-goroutine buffers: an M is a single writer, so the buffer needs no synchronisation at all. The per-goroutine view is reconstructed by the reader from the event stream — GoStart, GoStop, GoBlock and GoUnblock events carry the goroutine ID and a sequence number that lets the reader order events that were produced concurrently.

The per-goroutine bookkeeping that remains in the runtime is small:

go
// src/runtime/tracestatus.go:146
type traceSchedResourceState struct {
	// statusTraced indicates whether a status event was traced for this resource
	// a particular generation.
	//
	// There are 3 of these because when transitioning across generations, traceAdvance
	// needs to be able to reliably observe whether a status was traced for the previous
	// generation, while we need to clear the value for the next generation.
	statusTraced [3]atomic.Uint32

	// seq is the sequence counter for this scheduling resource's events.
	// The purpose of the sequence counter is to establish a partial order between
	// events that don't obviously happen serially (same M) in the stream ofevents.
	//
	// There are two of these so that we can reset the counter on each generation.
	// This saves space in the resulting trace by keeping the counter small and allows
	// GoStatus and GoCreate events to omit a sequence number (implicitly 0).
	seq [2]uint64
}

The seq counter is the clever bit: two Ms can emit events about the same goroutine concurrently, and the reader cannot tell which came first from the timestamps alone. The sequence number gives it a tiebreaker.

Writing an event

Events are written through a traceWriter, a value type whose methods return the writer so calls can be chained:

go
// src/runtime/tracebuf.go:68
// event writes out the bytes of an event into the event stream.
//
// nosplit because it's part of writing an event for an M, which must not
// have any stack growth.
//
//go:nosplit
func (w traceWriter) event(ev tracev2.EventType, args ...traceArg) traceWriter {
	// N.B. Everything in this call must be nosplit to maintain
	// the stack growth related invariants for writing events.

	// Make sure we have room.
	w, _ = w.ensure(1 + (len(args)+1)*traceBytesPerNumber)

	// Compute the timestamp diff that we'll put in the trace.
	ts := traceClockNow()
	if ts <= w.traceBuf.lastTime {
		ts = w.traceBuf.lastTime + 1
	}
	tsDiff := uint64(ts - w.traceBuf.lastTime)
	w.traceBuf.lastTime = ts

	// Write out event.
	w.byte(byte(ev))
	w.varint(tsDiff)
	for _, arg := range args {
		w.varint(uint64(arg))
	}
	return w
}

Three things to notice:

Timestamps are deltas, not absolute. The first event in a buffer carries its absolute timestamp; every subsequent one carries the difference. The delta is at most a nanosecond or two, so a varint encodes it in one byte.
Timestamps are forced to be strictly increasing. if ts <= lastTime { ts = lastTime + 1 } — the clock is not guaranteed to be monotonic at that granularity, and a trace with equal timestamps would be ambiguous.
nosplit. The whole path is marked nosplit because writing an event happens on the syscall slow path, where the stack must not move.

The buffer itself is a fixed-size byte array with a header:

go
// src/runtime/tracebuf.go:258
// traceBufHeader is per-P tracing buffer.
type traceBufHeader struct {
	link     *traceBuf // in trace.empty/full
	lastTime traceTime // when we wrote the last event
	pos      int       // next write offset in arr
	lenPos   int       // position of batch length value
}

// traceBuf is per-M tracing buffer.
//
// TODO(mknyszek): Rename traceBuf to traceBatch, since they map 1:1 with event batches.
type traceBuf struct {
	_ sys.NotInHeap
	traceBufHeader
	arr [tracev2.MaxBatchSize - unsafe.Sizeof(traceBufHeader{})]byte // underlying buffer for traceBufHeader.buf
}

MaxBatchSize is 64 KiB. When the buffer runs out, refill flushes it to the full queue and grabs a fresh one:

go
// src/runtime/tracebuf.go:189
	// Write the buffer's header.
	if w.exp == tracev2.NoExperiment {
		w.byte(byte(tracev2.EvEventBatch))
	} else {
		w.byte(byte(tracev2.EvExperimentalBatch))
		w.byte(byte(w.exp))
	}
	w.varint(uint64(w.gen))
	w.varint(mID)
	w.varint(uint64(ts))
	w.traceBuf.lenPos = w.varintReserve()

The lenPos slot is reserved now and filled in at flush time with the length of the batch — the classic “reserve space, patch it later” trick, because the length is not known until the batch is complete.

The traceLocker and the reentrancy guard

Before writing anything, an M must prove that tracing is on and claim the right to write:

go
// src/runtime/traceruntime.go:195
// traceAcquireEnabled is the traceEnabled path for traceAcquire. It's explicitly
// broken out to make traceAcquire inlineable to keep the overhead of the tracer
// when it's disabled low.
//
// nosplit because it's called by traceAcquire, which is nosplit.
//
//go:nosplit
func traceAcquireEnabled() traceLocker {
	// Any time we acquire a traceLocker, we may flush a trace buffer. But
	// buffer flushes are rare. Record the lock edge even if it doesn't happen
	// this time.
	lockRankMayTraceFlush()

	// Prevent preemption.
	mp := acquirem()

	// Check if we're already tracing. It's safe to be reentrant in general,
	// because this function (and the invariants of traceLocker.writer) ensure
	// that it is.
	if mp.trace.writing.Load() {
		mp.trace.reentered++
		return traceLocker{mp, mp.trace.entryGen}
	}

The writing flag is the guard against reentrancy: writing an event can trigger a stack growth, which can trigger a GC, which can emit trace events, which would try to write again. The reentrant call notices the flag and returns a locker bound to the same generation without touching the buffer.

There is also an important subtlety in trace.enabled versus trace.gen:

go
// src/runtime/trace.go:264
	// enabled indicates whether tracing is enabled, but it is only an optimization,
	// NOT the source of truth on whether tracing is enabled. Tracing is only truly
	// enabled if gen != 0. This is used as an optimistic fast path check.
	//
	// Transitioning this value from true -> false is easy (once gen is 0)
	// because it's OK for enabled to have a stale "true" value. traceAcquire will
	// always double-check gen.

trace.enabled is a plain bool read without synchronisation — a data race on paper, made safe by the world-stopping barrier used when the trace starts and stops.

The events themselves

The event type list is the vocabulary of the tracer, and it is short enough to read in full:

go
// src/internal/trace/tracev2/events.go:16
const (
	EvNone EventType = iota // unused

	// Structural events.
	EvEventBatch // start of per-M batch of events [generation, M ID, timestamp, batch length]
	EvStacks     // start of a section of the stack table [...EvStack]
	EvStack      // stack table entry [ID, ...{PC, func string ID, file string ID, line #}]
	EvStrings    // start of a section of the string dictionary [...EvString]
	EvString     // string dictionary entry [ID, length, string]
	EvCPUSamples // start of a section of CPU samples [...EvCPUSample]
	EvCPUSample  // CPU profiling sample [timestamp, M ID, P ID, goroutine ID, stack ID]
	EvFrequency  // timestamp units per sec [freq]

	// Procs.
	EvProcsChange // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack ID]
	EvProcStart   // start of P [timestamp, P ID, P seq]
	EvProcStop    // stop of P [timestamp]
	EvProcSteal   // P was stolen [timestamp, P ID, P seq, M ID]
	EvProcStatus  // P status at the start of a generation [timestamp, P ID, status]

	// Goroutines.
	EvGoCreate            // goroutine creation [timestamp, new goroutine ID, new stack ID, stack ID]
	EvGoCreateSyscall     // goroutine appears in syscall (cgo callback) [timestamp, new goroutine ID]
	EvGoStart             // goroutine starts running [timestamp, goroutine ID, goroutine seq]
	EvGoDestroy           // goroutine ends [timestamp]
	EvGoDestroySyscall    // goroutine ends in syscall (cgo callback) [timestamp]
	EvGoStop              // goroutine yields its time, but is runnable [timestamp, reason, stack ID]
	EvGoBlock             // goroutine blocks [timestamp, reason, stack ID]
	EvGoUnblock           // goroutine is unblocked [timestamp, goroutine ID, goroutine seq, stack ID]
	EvGoSyscallBegin      // syscall enter [timestamp, P seq, stack ID]
	EvGoSyscallEnd        // syscall exit [timestamp]
	EvGoSyscallEndBlocked // syscall exit and it blocked at some point [timestamp]
	EvGoStatus            // goroutine status at the start of a generation [timestamp, goroutine ID, M ID, status]

Everything after that is GC, STW, annotations, coroutine switches and the experimental allocation events. Every event is a one-byte type followed by varint-encoded arguments, and every “stack ID” argument is an index into the trace’s stack table.

Emitting one looks like this:

go
// src/runtime/traceruntime.go:423
// GoStart emits a GoStart event.
//
// Must be called with a valid P.
func (tl traceLocker) GoStart() {
	gp := getg().m.curg
	pp := gp.m.p
	w := tl.eventWriter(tracev2.GoRunnable, tracev2.ProcRunning)
	w.event(tracev2.EvGoStart, traceArg(gp.goid), gp.trace.nextSeq(tl.gen))
	if pp.ptr().gcMarkWorkerMode != gcMarkWorkerNotWorker {
		w.event(tracev2.EvGoLabel, trace.markWorkerLabels[tl.gen%2][pp.ptr().gcMarkWorkerMode])
	}
}

Note eventWriter rather than rawEventWriter: before the event is written, the tracer emits status events for the G and the P if their status has not already been reported for this generation. That is how the trace reader knows that goroutine 42 was “running” or “waiting” at the start of a generation without having to infer it.

Deduplication: strings, stacks and types

A busy program produces the same stack thousands of times. Writing them all would be absurd, so the tracer keeps three tables — one for strings, one for stacks, one for types — and refers to them by ID.

The backing store is a lock-free, append-only 4-ary hash trie:

go
// src/runtime/tracemap.go:26
// traceMap is a map of a variable-sized array of bytes to a unique ID.
//
// Because traceMap just operates on raw bytes, this type is used as the
// backing store for both the trace string table and trace stack table,
// the latter of which is just an array of PCs.
//
// ID 0 is reserved for arrays of bytes of size zero.
type traceMap struct {
	root atomic.UnsafePointer // *traceMapNode (can't use generics because it's notinheap)
	_    cpu.CacheLinePad
	seq  atomic.Uint64
	_    cpu.CacheLinePad
	mem  traceRegionAlloc
}

and the memory for the table’s contents comes from a bump allocator that lives outside the Go heap:

go
// src/runtime/traceregion.go:15
// traceRegionAlloc is a thread-safe region allocator.
// It holds a linked list of traceRegionAllocBlock.
type traceRegionAlloc struct {
	lock     mutex
	dropping atomic.Bool          // For checking invariants.
	current  atomic.UnsafePointer // *traceRegionAllocBlock
	full     *traceRegionAllocBlock
}

// traceRegionAllocBlock is a block in traceRegionAlloc.
//
// traceRegionAllocBlock is allocated from non-GC'd memory, so it must not
// contain heap pointers. Writes to pointers to traceRegionAllocBlocks do
// not need write barriers.
type traceRegionAllocBlock struct {
	_ sys.NotInHeap
	traceRegionAllocBlockHeader
	data [traceRegionAllocBlockData]byte
}

Off-heap, not-in-heap memory, no write barriers: the same constraints the signal handler imposes on the CPU profiler, applied here because the tracer must be safe to call from GC-adjacent code.

Generations and the file format

A “generation” is one contiguous stretch of trace data. The tracer starts a new generation when it advances (which happens on Stop, and on subscriber changes), and the file format records which version it is:

go
// src/internal/trace/version/version.go:17
const (
	Go111   Version = 11 // v1
	Go119   Version = 19 // v1
	Go121   Version = 21 // v1
	Go122   Version = 22 // v2
	Go123   Version = 23 // v2
	Go125   Version = 25 // v2
	Go126   Version = 26 // v2
	Current         = Go126
)

var versions = map[Version][]tracev2.EventSpec{
	// Go 1.11–1.21 use a different parser and are only set here for the sake of
	// Version.Valid.
	Go111: nil,
	Go119: nil,
	Go121: nil,

	Go122: tracev2.Specs()[:tracev2.EvUserLog+1],           // All events after are Go 1.23+.
	Go123: tracev2.Specs()[:tracev2.EvExperimentalBatch+1], // All events after are Go 1.25+.
	Go125: tracev2.Specs()[:tracev2.EvClockSnapshot+1],     // All events after are Go 1.26+.
	Go126: tracev2.Specs(),
}

That table is the whole compatibility story: each trace version knows which event types exist in it, and events added in later Go versions are simply truncated off the spec list for older versions. The version lives in a sixteen-byte header at the front of the file:

go
// src/internal/trace/version/version.go:67
// headerFmt is the format of the header of all Go execution traces.
const headerFmt = "go 1.%d trace\x00\x00\x00"

go tool trace reads that header, picks the matching spec table, and replays the event stream. The tracer is also reachable from outside the standard library: the runtime notes that traceAdvance is called both by runtime/trace and by golang.org/x/exp/trace using go:linkname (src/runtime/trace.go:467), which is how third-party trace consumers drive the same machinery. go tool trace is the supported front end.

What it costs

Tracing is not free, and the cost is not in one place. It is spread across:

Every scheduling transition now emits an event: goroutine start, stop, block, unblock, syscall enter and exit.
Every event is a type byte plus varint-encoded arguments.
Every stack attached to an event has to be walked and hashed.
Start and stop of the trace require stopping the world.

The number people quote is “5–10% overhead”, and that is a rule of thumb rather than a guarantee: a program with a lot of goroutine churn pays more, and a program that spends its life in one tight loop pays almost nothing, because there are no transitions to record. The honest way to find out is to measure your program with and without.

Two knobs make it cheaper. GODEBUG=traceallocfree=1 is off by default because it is expensive; and the flight recorder keeps only the recent generations, so a long-running program does not accumulate an unbounded file.

Trade-offs

What the trace buys you: causality. You can see that goroutine 42 blocked on a channel receive at t=1.2ms, that goroutine 17 sent on it at t=1.1ms, that goroutine 17 was blocked on a mutex held by goroutine 3, and that goroutine 3 was in a GC assist. No amount of CPU profiling gives you that.

What it costs:

Volume. Every transition is recorded. A busy scheduler produces enormous traces.
Storage. Trace files are routinely hundreds of megabytes.
Overhead. A few percent, more if the program churns goroutines.
A non-portable format. The wire format is internal to the Go project and changes between versions, which is why go tool trace from a newer toolchain may refuse an older file.

What you give up by not tracing: the ability to answer “why”. A profile tells you where the CPU is; only a trace tells you why a goroutine was not using it.

Caveats

Traces are big and the UI will melt. Use the go tool trace -pprof=sched flag to extract a scheduler profile from a trace rather than staring at millions of rows in a browser.

The trace contains your data. Log messages and region names are recorded verbatim. If you put a token in a trace.Log, it is in the file.

Stack traces are deduplicated, not free. The first occurrence of a stack carries the cost of walking it; later occurrences cost a hash lookup.

SIGPROF interference. If you run a CPU profile and an execution trace at the same time, the tracer piggybacks the CPU samples onto the trace stream (EvCPUSample), but the two mechanisms still both pay for their own signal delivery.

The world stops at the start and end of the trace. On a program with microsecond latency requirements, that pause is visible.

Version skew. A trace written by Go 1.26 contains event types that Go 1.22’s reader does not know about. The spec tables handle that by truncation, but a very old reader of a very new trace will still lose the newest events.

Wrapping up

The one thing to remember: the execution tracer records events, not samples. Goroutine transitions, syscalls, GC phases and user annotations all become typed, timestamped, varint-encoded entries in per-M ring buffers that are deduplicated through lock-free hash tries and streamed to a reader goroutine.

The part people get wrong: assuming the tracer keeps a buffer per goroutine. It does not — it keeps a buffer per M, and reconstructs the per-goroutine timeline from the event stream using the per-goroutine sequence numbers.

What to go do about it: run go tool trace on a program that is slow, not one that is busy. Then stop looking at the flame graph and look at the “Scheduler latency profile” and the goroutine timeline — that is where the answer usually is.