Sijin T V
Sijin T V A passionate Software Engineer who contributes to the wonders happenning on the internet

Profiling Go Memory and CPU Bottlenecks with `go tool pprof` and `trace`

Guessing where CPU goes is how services die slowly. Go ships a world-class profiler; the real skill is using it correctly, because each profile type answers a different question and people routinely grab the wrong one.

Setup. Expose pprof on loopback only, never through a public route:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
package main

import (
	"log"
	"net/http"
	_ "net/http/pprof"
	"runtime"
	"time"
)

func main() {
	// Sample blocks >= 1ms and 1/1000 of contended mutex holders.
	// Both are off by default because they cost CPU; enable when chasing suspects.
	runtime.SetBlockProfileRate(1000000)
	runtime.SetMutexProfileFraction(1000)

	go func() {
		log.Println(http.ListenAndServe("127.0.0.1:6060", nil))
	}()

	// application loop
	time.Sleep(time.Hour)
}

CPU profiles are sampled at 100 Hz. In a 30-second profile that is 3,000 samples, so a function has to burn about 3% of CPU before it shows up in 90 samples — below that you are reading noise. Profile for at least 30 seconds under real load, never in isolation:

1
go tool pprof -http=:8081 'http://localhost:6060/debug/pprof/profile?seconds=30'

The flame graph is where the wins hide. This is how we found a json.Marshal call eating 23% of CPU in an API hot path; the fix was a hand-rolled marshaler and p99 dropped by 40%. Nothing in the architecture changed.

The heap profile is the most misunderstood one. It is sampled — by default one sample per 512 KiB allocated (runtime.MemProfileRate) — and it comes in two flavors that answer different questions:

  • inuse_space shows memory currently reachable. This is the leak detector: take a baseline, run for 24 hours, diff.
  • alloc_space shows total lifetime allocation volume. This finds churn, not leaks — and it is where sync.Pool and allocation elimination show their worth.

Diffing two dumps catches slow leaks that a single snapshot can’t:

1
2
go tool pprof -inuse_space -base mem_before.prof mem_after.prof
go tool pprof -top

The classic slow leak we keep seeing: a per-request cache that never evicts. In one service the heap grew ~20 MiB/day; the inuse diff pointed at a sync.Map storing resolved upstream hostnames for every request forever. An LRU with a cap flatlined the growth curve. The heap profile found it in one afternoon; the “log everything and guess” approach had been going for weeks.

Goroutine leaks are fastest to find via stacks, not heap. curl 'localhost:6060/debug/pprof/goroutine?debug=1' gives you every goroutine’s stack. A leak — thousands of goroutines blocked on a channel nobody will ever close — shows up as a wall of identical stacks. That diagnosis is usually faster than the heap diff and worth checking first when RSS climbs without an obvious allocator culprit.

go tool trace for the scheduler view. Five seconds is usually enough:

1
go tool trace 'http://localhost:6060/debug/pprof/trace?seconds=5'

The trace shows GC pauses (the purple GC bars), network and syscall activity, and scheduler starvation. The pattern to hunt: repeated GC spans that coincide with p99 spikes, or a handful of goroutines pinned and everything else waiting. Longer traces are megabytes of overhead; start at 5 seconds.

Production rules we enforce:

  • Never expose 6060 publicly. /debug/pprof/heap?debug=1 dumps the entire heap to any caller; profile?seconds=60 pegs a core on demand. Bind 127.0.0.1, or expose it only to a profiling jump box via network policy.
  • runtime.ReadMemStats itself stops the world briefly. Don’t call it from a microsecond hot path; sample it on an interval and ship the last value.
  • Lower MemProfileRate only while hunting a leak. At 64 KiB it roughly doubles allocation cost; set it back when the hunt is over.
  • Profile in CI under simulated load. A CPU profile from a benchmark on every PR is the cheapest regression detector you can buy; pprof output is stable enough to diff.

The profiler will not tell you what to fix — it tells you where to look, with numbers. The habit is: profile first, change second, profile again. Every big latency win we have shipped started in pprof and was confirmed there.

comments powered by Disqus