Watch Go's Garbage Collector Move Through Your Heap

Go's GC traces reveal exactly when the collector pauses your code and why. Most engineers never read them. Here's what the numbers mean.

Dafallah Ibrahim

— 2 min read
Share

A recent deep dive into Go's garbage collector walks the heap cycle by cycle, comparing the old and new GC implementations side by side. The takeaway: you can observe the collector with enough granularity to pinpoint exactly why your p99 latency spikes.

If you run Go services in production and you've never read a GC trace, you're missing the most direct performance diagnostic the runtime gives you.

Why this matters

GC pauses cause tail latency. When your service jumps from 2ms to 40ms, the garbage collector is the usual suspect. Without traces, you're guessing. The GC output tells you how long the collector stopped the world, how much heap it reclaimed, and whether your goroutines are being drafted into collection work.

How it works

Set GODEBUG=gctrace=1 and every collection cycle prints a line to stderr:

gc 42 @10.234s 3%: 0.012+2.1+0.008 ms clock, 32->32->16 MB, 34 MB goal, 8 P

Each field tells a story:

  • 42 — cycle number. Rising fast means heavy allocation pressure.
  • 3% — fraction of CPU spent on GC. Above 10% is a red flag.
  • 0.012+2.1+0.008 ms — three GC phases: STW sweep termination, concurrent mark, STW mark termination.
  • 32->32->16 MB — heap before GC, live during GC, live after GC. Middle number close to first means a large live set.
  • 34 MB goal — target heap size Go tries to stay under.

The two STW numbers — 0.012 and 0.008 — are your latency cost. The concurrent mark between them runs alongside your goroutines. The newer GC implementation has reduced these stop-the-world windows, but they're never zero.

Where this helps

  • p99 spikes: if STW times grow under load, GC pressure is your answer.
  • GOMEMLIMIT tuning: watch the goal vs actual heap to find the right ceiling for containers.
  • Allocation hotspots: fast-rising cycle numbers point to tight loops allocating in request paths.
  • Capacity planning: the heap goal reveals exactly how much memory Go wants before triggering a collection.

Watch out

gctrace writes to stderr on every cycle. In high-throughput services that's significant log volume — use it for diagnosis, not permanent production monitoring. The CPU percentage also includes GC assist time: when allocation outpaces marking, your own goroutines get pulled into collection work. That overhead shows up as CPU contention, not pauses, which makes it easy to misdiagnose.

Try it yourself

# Trace GC cycles from any Go binary
GODEBUG=gctrace=1 go run main.go 2>&1 | grep "^gc"

# For a running service, expose a trace endpoint:
import _ "net/http/pprof"
# Then capture 10 seconds of GC activity:
curl -o trace.out "http://localhost:8080/debug/pprof/trace?seconds=10"
go tool trace trace.out

TL;DR

  • What happened: Go's GC trace output exposes exact pause times and heap behavior for every collection cycle.
  • Why it matters: the STW phases in each trace line are your latency spikes — their size tells you if GC is the culprit.
  • What to try: run GODEBUG=gctrace=1 during your next load test and watch the numbers move.

Read more