vault

GODEBUG Diagnostics

19 min read

GODEBUG Diagnostics

GODEBUG is a comma-separated list of name=value pairs, supplied as an environment variable, that toggles runtime behavior. It carries two distinct kinds of setting that are easy to conflate. Since Go 1.21 it is the official backward-compatibility mechanism — settings like panicnil=1 or asynctimerchan=0 let old code keep its old behavior on a new toolchain (go.dev/doc/godebug). But long before that, and still, it is also a diagnostic switchboard: gctrace, schedtrace, scheddetail, inittrace, scavtrace and friends ask the runtime to print line-per-event tracing to standard error with essentially zero setup (runtime package environment variables). This note covers the diagnostic settings; the compatibility mechanism, the //go:debug directive, and the go.mod/go.work godebug line are covered in the sibling note GODEBUG and Runtime Configuration Knobs.

Mental Model

Think of the diagnostic GODEBUG settings as printf debugging built into the runtime. They are not a profiler and not the execution tracer — they emit no file, need no tooling, and produce a human-readable line on stderr each time the relevant subsystem does something. The trade is granularity for convenience: a gctrace line per GC cycle, or a schedtrace line every N milliseconds, is coarse, but it costs one environment variable and works on any binary — including one you did not build — in any environment, with no recompile and no instrumentation linked in.

The two kinds of GODEBUG setting differ in a way that has real consequences. Compatibility settings (panicnil, asynctimerchan, http2client, …) are part of the Go 1 compatibility surface: their names are registered in internal/godebugs, their defaults are version-pinned by go.mod, each has a runtime/metrics counter, and Go promises to keep them for at least two years (four releases). Diagnostic settings (gctrace, schedtrace, …) have none of that contract — the runtime documentation explicitly says “the format of this line is subject to change,” and settings can be added or removed between releases (allocfreetrace is a removed one — see below). Conflating the two is the single most common GODEBUG mistake.

flowchart TD
  ENV["GODEBUG=gctrace=1,schedtrace=1000,inittrace=1"]
  ENV --> RT["Go runtime parses GODEBUG once at startup"]
  RT --> GC["GC cycle completes"] --> L1["stderr: 'gc 1 @0.5s 2%: 0.01+1.3+0.07 ms clock ...'"]
  RT --> SCH["every 1000ms"] --> L2["stderr: 'SCHED 1000ms: gomaxprocs=8 idleprocs=6 ...'"]
  RT --> INIT["each package init runs"] --> L3["stderr: 'init time @0.16ms, 0.01 ms clock, 312 bytes, 4 allocs'"]
  RT -.->|same variable, different contract| COMPAT["compatibility settings:\npanicnil, asynctimerchan, http2*\n(see GODEBUG and Runtime Configuration Knobs)"]

Diagram: the diagnostic GODEBUG settings hook subsystem events (GC cycle, scheduler tick, package init) and write a stderr line each time. The insight: GODEBUG is one environment variable carrying two unrelated kinds of setting — diagnostic tracing (this note) and the post-1.21 compatibility toggles (the sibling note) — and conflating them causes confusion about defaults, stability, and the 2-year support promise.

Mechanical Walk-through

The runtime parses GODEBUG once during startup into an internal table — the recognized names and their doc comments live in src/runtime/extern.go (extern.go). A diagnostic setting then arms a hook in the corresponding subsystem: a flag the GC checks at the end of every cycle, a timer the scheduler arms, a branch in the package-init loop. There is no buffering and no log file. The runtime writes formatted text straight to file descriptor 2 (stderr) using its own minimal print routines — not the fmt package, not log. That is a deliberate property: because the diagnostic printer depends on neither the heap nor goroutines making progress, it keeps working even when the program is crashing, the scheduler is wedged, or the GC is mid-pause. The flip side is that diagnostic output can interleave with a panic traceback on the same fd 2.

Two behaviors trip people up. First, unrecognized GODEBUG names are silently ignored when passed via the environment — a typo produces no output and no error, which is a frequent “it didn’t work.” (This is not true of the compatibility path: a //go:debug directive or a go.mod godebug line with an unrecognized name is a build error from Go 1.21/1.23 onward — see GODEBUG and Runtime Configuration Knobs.) Second, diagnostic settings are not version-stable: their names, output formats, and defaults can change between Go releases, and the extern.go comment repeats “the format of this line is subject to change” for each tracing setting. Always check the runtime docs for your exact Go version; never pin long-lived tooling to one release’s format.

gctrace — one line per garbage collection

GODEBUG=gctrace=1 makes the garbage collector emit one line to stderr at the end of every cycle. The runtime documents the exact shape, and helpfully maps each field to its runtime/metrics equivalent (extern.go):

gc 1 @0.012s 4%: 0.018+1.3+0.076 ms clock, 0.14+0.31/1.2/0+0.61 ms cpu, 4->4->1 MB, 5 MB goal, 0 MB stacks, 0 MB globals, 8 P

Walking the line token by token, against the documented format gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # MB stacks, #MB globals, # P:

  • gc 1 — the GC number, incremented at each collection. Useful for spotting GC frequency: if this climbs fast, the program is collecting too often (often a GOGC or allocation-rate problem).
  • @0.012s — wall-clock time since program start.
  • 4% — the cumulative fraction of CPU spent in GC since the program started. A steadily-rising number here is the headline “GC is expensive” signal; the GC guide treats it as the primary cost metric.
  • 0.018+1.3+0.076 ms clock — wall-clock time in the three GC phases: STW sweep-termination + concurrent mark-and-scan + STW mark-termination. The two STW numbers — 0.018 and 0.076 ms here — are the latency-critical ones, the pauses a request can actually feel (see Stop-the-World Pauses). The middle number is concurrent and runs alongside the program.
  • 0.14+0.31/1.2/0+0.61 ms cpu — the same three phases as CPU time summed across all Ps. The middle phase is itself split assist/dedicated/idle: 0.31 ms of mark assist (GC work done inline by allocating goroutines as a brake — see GC Assists and Mark Workers), 1.2 ms on dedicated mark workers, 0 ms of idle-time marking. A large assist share means the pacer is behind and is taxing application goroutines to catch up.
  • 4->4->1 MB — heap size at GC start, at GC end, and live heap after the cycle (the docs map the last to /gc/scan/heap:bytes). The gap between the first two is allocation during the cycle; the third is what survived.
  • 5 MB goal — the heap-size target the pacer aimed for this cycle (/gc/heap/goal:bytes). Compare it to the 4->4->... actuals: if the run overshoots the goal repeatedly, the pacer is losing the race against allocation.
  • 0 MB stacks — estimated scannable goroutine-stack size (/gc/scan/stack:bytes).
  • 0 MB globals — scannable global-variable size (/gc/scan/globals:bytes).
  • 8 P — number of processors used (/sched/gomaxprocs:threads).

If the line ends with (forced), that cycle was triggered by an explicit runtime.GC() call rather than by the pacer. Two companion settings deepen this: gccheckmark=1 runs a second, world-stopped verification mark pass and panics if concurrent mark missed a reachable object (a GC-correctness debug aid), and gcpacertrace=1 dumps the pacer’s internal state so you can see why it chose the goal it did.

schedtrace and scheddetail — scheduler state

GODEBUG=schedtrace=1000 makes the scheduler print one summary line to stderr every 1000 milliseconds. The exact field set comes straight from the schedtrace function in src/runtime/proc.go (proc.go):

SCHED 1000ms: gomaxprocs=8 idleprocs=6 threads=11 spinningthreads=1 needspinning=0 idlethreads=3 runqueue=2 [ 0 1 0 0 0 0 0 0 ] schedticks=[ 412 388 401 7 5 3 2 0 ]
  • SCHED 1000ms — milliseconds since program start.
  • gomaxprocs=8 — current GOMAXPROCS: how many Ps exist.
  • idleprocs=6 — Ps currently idle. If this stays high while runqueue is non-empty you have a latency problem, not a throughput one — work is waiting while processors sit idle.
  • threads=11 — total OS threads (Ms) the runtime owns.
  • spinningthreads=1 — Ms actively spinning to find runnable work (the work-stealing handoff — see Work Stealing Scheduler).
  • needspinning=0 — whether the scheduler wants another M to start spinning.
  • idlethreads=3 — parked Ms.
  • runqueue=2 — length of the global run queue.
  • [ 0 1 0 0 0 0 0 0 ] — the length of each P’s local run queue, in order. A long tail here, or a heavily-skewed distribution, signals load imbalance the work-stealer is not keeping up with.
  • schedticks=[ ... ] — per-P scheduler-tick counts (how many times each P ran the scheduler), exposing how much each P actually worked.

Adding scheddetail=1 alongside schedtrace=N upgrades the output to a detailed multi-line dump every N ms: the summary line gains gcwaiting, nmidlelocked, stopwait, sysmonwait; then one P line per processor (status, schedtick, syscalltick, owning m, runqsize, gfreecnt, timerslen); one M line per thread (p, curg, mallocing, throwing, preemptoff, locks, dying, spinning, blocked, lockedg); and one G line per goroutine (status, wait reason, m, lockedm). scheddetail does nothing without schedtrace also set — it only upgrades existing schedtrace output, and GODEBUG=scheddetail=1 alone is silent. The full field-by-field breakdown lives in Scheduler Tracing and GODEBUG schedtrace; the point here is that schedtrace is the cheapest way to answer “is my scheduler thrashing / are run queues backing up?” without a full execution trace.

inittrace — package initialization profiling

GODEBUG=inittrace=1, added in Go 1.16 (Go 1.16 release notes), makes the runtime emit one line per package that has init work, summarizing time and allocation. The documented format is init # @#ms, # ms clock, # bytes, # allocs (extern.go):

init internal/bytealg @0.008 ms, 0 ms clock, 0 bytes, 0 allocs
init runtime @0.059 ms, 0.026 ms clock, 0 bytes, 0 allocs
init time @0.157 ms, 0.011 ms clock, 312 bytes, 4 allocs
  • init time — the package name.
  • @0.157 ms — when the init started, in milliseconds relative to program start.
  • 0.011 ms clock — wall-clock time the package’s init work took.
  • 312 bytes — heap memory allocated during that package’s init.
  • 4 allocs — number of heap allocations during it.

No line is printed for packages with neither user-defined nor compiler-generated init work, and none for inits run as part of plugin loading. This is the tool for diagnosing slow program startup: a package compiling regexes, building large tables, or reading config in init() shows up immediately as an outlier in the clock, bytes, or allocs columns.

scavtrace — the memory scavenger

GODEBUG=scavtrace=1 makes the runtime emit one line, roughly once per GC cycle, summarizing the scavenger’s work returning memory to the OS. The documented format is scav # KiB work (bg), # KiB work (eager), # KiB total, #% util (extern.go): work (bg) is memory returned in the background since the last line, work (eager) is memory returned eagerly, the third figure is the address space currently returned to the OS, and % util is the fraction of unscavenged heap that is in use. A trailing (forced) means a debug.FreeOSMemory() call forced the scavenge. scavtrace and gctrace together tell the whole memory story: gctrace shows allocation and the live heap, scavtrace shows what is being handed back.

madvdontneed — how memory is returned to the OS

madvdontneed controls the madvise(2) advice the scavenger passes to the kernel when returning unused heap pages, and its semantics are OS-dependent — this is the polarity that is genuinely easy to get backwards. The authoritative wording is in extern.go (runtime env vars):

  • On Linux, madvdontneed=0 makes the runtime use MADV_FREE instead of MADV_DONTNEED. MADV_FREE is lazy reclaim: the kernel marks the pages reclaimable but only actually takes them back under memory pressure, so the process can look like it is using memory it has logically released. The Linux default (no setting) is the prompt MADV_DONTNEED, under which freed pages drop out of RSS immediately.
  • On the BSDs and Illumos/Solaris, the polarity is the mirror image: there madvdontneed=1 makes the runtime use MADV_DONTNEED instead of MADV_FREE. The documentation explicitly notes this is “less efficient, but causes RSS numbers to drop more quickly” on those platforms.

The historical context resolves the rest. Go 1.16 flipped the Linux default to prompt MADV_DONTNEED so that process-level statistics like Resident Set Size (RSS), as seen by top, cgroup accounting, and monitoring agents, accurately reflect physical memory in use; before 1.16 you had to set GODEBUG=madvdontneed=1 to get that, and the Go 1.16 notes state explicitly that “systems that are currently using GODEBUG=madvdontneed=1 … no longer need to set this environment variable” (Go 1.16 release notes). So on Linux post-1.16, madvdontneed=0 is the only relevant override — it opts back into the lazy MADV_FREE behavior — and madvdontneed=1 is now a redundant no-op against the default. The reason this counts as a “diagnostic” knob: with MADV_FREE a Go process can appear to use more memory than it logically holds, confusing memory dashboards; choosing prompt reclaim makes the numbers honest at a small reclaim-cost. The per-OS polarity is verbatim from the extern.go doc comment at the go1.26.0 tag (verified 2026-05-28): on Linux madvdontneed=0 ⇒ MADV_FREE; on the BSDs and Illumos/Solaris madvdontneed=1 ⇒ MADV_DONTNEED.

Other diagnostic settings worth knowing

The runtime carries a long tail of debug knobs (extern.go). memprofilerate=N sets runtime.MemProfileRate, the heap profiler’s sampling rate (0 disables heap profiling). profstackdepth=128 (the default) caps the stack depth recorded by all pprof profilers except the CPU profiler; values above 1024 silently clamp to 1024. tracebackancestors=N extends panic tracebacks with the stacks at which goroutines were created, up to N ancestors — invaluable for “who spawned this leaked goroutine” (see Goroutine Leaks). clobberfree=1 overwrites freed objects with bad content so a use-after-free shows up loudly. invalidptr=1 (the default) crashes on a clearly invalid pointer in a pointer-typed slot; invalidptr=0 disables that check as a temporary workaround. efence=1 puts every allocation on its own page and never recycles addresses, catching out-of-bounds access. harddecommit=1 also strips protections from memory returned to the OS (the only mode on Windows; a Linux-only debug aid for scavenger issues elsewhere). gcstoptheworld=1 makes every GC fully stop-the-world (=2 also disables concurrent sweeping). gcshrinkstackoff=1 stops goroutine stacks from ever shrinking. asyncpreemptoff=1 disables signal-based asynchronous preemption. sbrk=1 replaces the allocator and GC with a trivial never-reclaiming allocator. checkfinalizers=1 (added in Go 1.25) runs partial STW collections to surface common finalizer/cleanup mistakes and prints a checkfinalizers:-prefixed line per GC cycle. Several of these — efence, clobberfree, gccheckmark, sbrk — dramatically slow the program or change its memory behavior; they are debugging aids, never production flags.

A removed setting — allocfreetrace. Until Go 1.23, allocfreetrace=1 printed a stack trace on every object allocation and free. It was deleted by CL 583376 (commit 11047345, 2024-04-24), whose message is blunt about why: “It’s not terribly useful because it has a really huge overhead, making it not feasible to use except for the most trivial programs. A follow-up CL will replace it with something that is both more thorough and also lower overhead.” It is consequently absent from the src/runtime/extern.go doc comment at the go1.26.0 tag (verified 2026-05-28) — so on any Go 1.23-or-later toolchain it is just another unrecognized name, silently ignored. This is the canonical example of the “settings get removed” hazard below: it was never a stable surface, carried no support promise, and vanished without a release-note callout because it was a niche runtime debug aid rather than a Go 1 compatibility setting.

Code / Usage Examples

Setting diagnostics at the command line

# One GC line per cycle, plus a scheduler summary every 1s:
GODEBUG=gctrace=1,schedtrace=1000 ./myserver
 
# Detailed scheduler dump every 5s (scheddetail needs schedtrace too):
GODEBUG=schedtrace=5000,scheddetail=1 ./myserver
 
# Profile startup: one line per package init:
GODEBUG=inittrace=1 ./myserver
 
# Watch the scavenger return memory to the OS:
GODEBUG=scavtrace=1 ./myserver
 
# Opt back into lazy MADV_FREE on Linux (rarely wanted; makes RSS lag):
GODEBUG=madvdontneed=0 ./myserver

Each is just an environment variable in front of the binary; nothing is compiled in, and you can apply any of them to a binary you did not build. Output goes to stderr — redirect with 2> trace.log to capture it without disturbing the program’s own stdout. Multiple settings are comma-separated with no spaces; a stray space silently breaks the parse for everything after it.

Reading whether a compatibility opt-out is in use

The diagnostic story connects back to metrics: every compatibility GODEBUG setting has a counter /godebug/non-default-behavior/<name>:events that increments whenever the non-default (old) behavior is taken (go.dev/doc/godebug). That lets a service observe its own use of a deprecated path:

s := []metrics.Sample{{Name: "/godebug/non-default-behavior/panicnil:events"}}
metrics.Read(s)                                  // 1 fill the value in place
if s[0].Value.Kind() == metrics.KindUint64 &&    // 2 guard: metric exists here
	s[0].Value.Uint64() > 0 {                    // 3 counter moved => path taken
	log.Printf("panic(nil) compatibility path taken %d times",
		s[0].Value.Uint64())
}

Line 1 reads the single counter. Line 2 guards with Kind() because a runtime/metrics name unknown to the running Go version comes back as KindBad, and calling Uint64() on that would panic. Line 3 checks whether the counter is nonzero — if it is, some dependency is relying on the panicnil=1 opt-out, which is exactly what you want to know before that opt-out is removed in a future Go release. This is the production-grade complement to the diagnostic stderr tracing: the tracing tells you what a subsystem is doing now; the counter tells you, over the whole process lifetime, whether a compatibility shim was ever needed.

Failure Modes and Common Misunderstandings

Typos are silent. GODEBUG=gctrace=1 with a missing letter — gtrace=1 — produces no output and no warning, because unrecognized environment-supplied names are ignored. Copy names verbatim from the runtime docs for your Go version.

scheddetail without schedtrace. GODEBUG=scheddetail=1 alone does nothing; it only upgrades schedtrace output to the multi-line form. You must set both, e.g. schedtrace=1000,scheddetail=1.

Confusing diagnostic settings with compatibility settings. gctrace is a diagnostic; panicnil is a compatibility toggle. Only the compatibility settings are version-defaulted by go.mod///go:debug, only they carry a /godebug/non-default-behavior/* counter, and only they are covered by the two-year (four-release) support promise. Diagnostic settings’ formats and defaults can and do change between Go releases — extern.go says so explicitly for every tracing setting — so never parse gctrace or schedtrace output with a regex pinned to one Go version in long-lived tooling.

Settings get removed. Diagnostic settings are not a stable surface. allocfreetrace, once a documented setting that printed a stack trace on every allocation and free, was removed in Go 1.23 (CL 583376, 2024-04-24) and no longer appears in the extern.go doc comment (see the allocfreetrace paragraph above). Tooling that assumes a setting still exists will simply produce no output — the typo-is-silent rule means a removed setting fails the same quiet way.

Diagnostic settings have real cost. gctrace, schedtrace, inittrace, scavtrace are cheap — a few stderr lines. But efence, clobberfree, gccheckmark, sbrk, and checkfinalizers drastically slow execution and/or change memory behavior; they are debugging tools, never production flags. Turning on gccheckmark in production to “be safe” instead adds a world-stopped mark pass to every GC.

Output ordering during a crash. Because diagnostic output goes straight to fd 2 with the runtime’s own printer (no buffering, no fmt), it can interleave with a panic traceback or other stderr writes. That is intentional — the printer must work when the program is broken and the heap is unusable — but it means you may need to untangle the log after a crash.

Alternatives and When to Choose Them

  • metrics — the machine-readable equivalent. gctrace gives you a human line per GC cycle; the /gc/... metrics give you the same numbers as queryable values for a dashboard, with no fragile text parsing. The runtime/metrics package was created in part because “automated metric collection systems ignore gctrace.” Use gctrace for a quick interactive look; use runtime/metrics for monitoring.
  • The Go Execution Tracer — when a schedtrace summary says “something is wrong” but not what, a full execution trace reconstructs the exact goroutine-by-goroutine timeline. schedtrace is the cheap probe; the tracer is the heavy follow-up.
  • pprof and Profiling — for stack-attributed hotspots and contention call sites. inittrace finds which package is slow at startup; a CPU profile finds which function.
  • GODEBUG and Runtime Configuration Knobs — the sibling note covering the compatibility role of GODEBUG, the //go:debug directive, and the go.mod/go.work godebug line. If you are reasoning about defaults, version-pinning, or the 2-year support promise, that is the note — this one is strictly the diagnostic tracing settings.

Production Notes

gctrace=1 and schedtrace are safe enough to leave on in staging — or even production — for a service whose stderr is captured: the per-cycle line is negligible, and the GC guide uses gctrace output as a primary teaching aid for diagnosing GC behavior. The typical workflow is incremental and cheap-first: notice high latency, set GODEBUG=gctrace=1 to see whether STW pauses or GC frequency explain it; set schedtrace=1000 to see whether run queues are backing up while Ps sit idle; set inittrace=1 if the symptom is slow startup; set scavtrace=1 if the symptom is RSS that will not come down. Only once you know which subsystem is implicated do you reach for the heavier, file-producing tools — the execution tracer or pprof. The diagnostic GODEBUG settings are the first probe precisely because they cost one environment variable and work on any binary; the file-producing tools are the targeted follow-up. Two operational cautions: never ship a build with efence/clobberfree/gccheckmark left on, and never let long-lived log-parsing tooling assume a gctrace/schedtrace line format — pin the Go version or, better, read the same numbers from metrics instead.

See Also

Graph View

Backlinks