Profiling with pprof

Capturing a profile

Two doors lead to the same data. For a batch program, drive runtime/pprof by hand:

import (
	"os"
	"runtime/pprof"
)

func main() {
	f, _ := os.Create("cpu.out")
	defer f.Close()
	pprof.StartCPUProfile(f) // sample the CPU while work runs
	defer pprof.StopCPUProfile()

	doExpensiveWork()
}

For a long-running server, import net/http/pprof for its side effects — it registers handlers under /debug/pprof/:

import (
	"net/http"
	_ "net/http/pprof" // registers /debug/pprof/* on the default mux
)

func main() {
	go http.ListenAndServe("localhost:6060", nil)
	// ... your real server ...
}

# Pull a 30-second live CPU profile straight into pprof:
$ go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
# Heap (in-use memory) and goroutine snapshots:
$ go tool pprof http://localhost:6060/debug/pprof/heap
$ go tool pprof http://localhost:6060/debug/pprof/goroutine

But the easiest harness of all is a benchmark — it both stresses the code and writes the profile:

$ go test -bench . -cpuprofile cpu.out -memprofile mem.out
goos: darwin
goarch: amd64
BenchmarkParse-8   	  248913	      4821 ns/op	    2048 B/op	      33 allocs/op
PASS
ok      example.com/app   1.402s

graph LR
PROG["program / benchmark"] --> PROF["profile<br/>cpu.out · mem.out"]
PROF --> TOOL["go tool pprof"]
TOOL --> HOT["hot path<br/>top · list · web (flame graph)"]

Reading the profile

Open the profile and explore it interactively:

$ go tool pprof cpu.out
(pprof) top
Showing nodes accounting for 1.30s, 92.86% of 1.40s total
      flat  flat%   sum%        cum   cum%
     0.70s 50.00% 50.00%      0.70s 50.00%  example.com/app.parseField
     0.40s 28.57% 78.57%      1.10s 78.57%  example.com/app.Parse
     0.20s 14.29% 92.86%      0.20s 14.29%  runtime.mallocgc

• flat = time spent in the function itself; cum = time including everything it called.
• parseField is the leaf hot spot (50% flat); mallocgc showing up means allocations are a cost.

Drill into a function line by line, then render a flame graph:

(pprof) list parseField     # annotate the source with per-line cost
(pprof) web                 # open an SVG call graph in the browser
(pprof) png > profile.png   # or save it

A flame graph stacks callers vertically and widths-by-cost horizontally — the widest box at any level is where the time goes. go tool pprof -http=:8080 cpu.out serves an interactive flame graph in your browser, the friendliest view.

For memory, point pprof at the heap profile and switch sample types:

$ go tool pprof mem.out
(pprof) top                 # default: in-use space
(pprof) sample_index=alloc_space
(pprof) top                 # total bytes ever allocated — finds churn

Hot spots and leaks

Two patterns recur. Allocation hot spots show up as runtime.mallocgc high in the CPU profile or large alloc_space in the heap profile — the fix is usually to reuse buffers (sync.Pool, preallocated slices) or avoid converting between string and []byte.

A goroutine leak appears in the goroutine profile as an ever-growing count parked at the same stack frame:

$ go tool pprof http://localhost:6060/debug/pprof/goroutine
(pprof) top
   10000   95%   chan receive   example.com/app.worker   # 10k stuck here!

Ten thousand goroutines blocked on the same channel receive means senders vanished without closing the channel or cancelling a context — a classic leak. The count climbing over time is the tell.

See also

• benchmarks — the easiest profiling harness (-cpuprofile/-memprofile).
• the race detector — the other go test instrument, for correctness not speed.
• GC & stacks — what allocation hot spots cost the garbage collector.
• the go toolchain — go tool pprof and friends.

Next: catching the bugs that only appear under concurrency — The Race Detector.

Related topics