Profiling Go with pprof: Finding the Real Bottleneck

Every engineer has an intuition about why their code is slow, and it is often wrong. The loop that looks expensive turns out to be irrelevant, while a harmless-looking fmt.Sprintf in a hot path accounts for 30% of CPU. Go ships pprof so you can measure the cost directly instead of guessing.

Step 0: define "slow" with a benchmark

You can't improve something you haven't measured. Start with a benchmark for the code path you care about:

func BenchmarkRenderInvoice(b *testing.B) {
    inv := sampleInvoice()
    b.ReportAllocs()
    for b.Loop() {
        _ = RenderInvoice(inv)
    }
}

Run it several times and save the output:

go test -bench=RenderInvoice -count=10 ./invoice > before.txt

Later you'll compare against this baseline with benchstat, which tells you whether a change is real or noise.

Collecting profiles

From a benchmark

go test -bench=RenderInvoice -cpuprofile=cpu.out -memprofile=mem.out ./invoice

From a running service

Import the handler package for its side effects and expose it on an internal-only port:

import _ "net/http/pprof"

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

Then capture 30 seconds of real traffic:

go tool pprof -http=:8081 http://127.0.0.1:6060/debug/pprof/profile?seconds=30

The -http flag opens an interactive web UI with a flame graph, a call graph, and annotated source.

Never expose /debug/pprof publicly. Profiles reveal internals, and some endpoints are expensive to serve.

The profiles that matter

The mutex and block profiles are off by default. Enable them with runtime.SetMutexProfileFraction and runtime.SetBlockProfileRate when you suspect contention.

Reading a flame graph

In the flame graph view:

• Width is cost. A wider box means more samples in that function and everything it calls.
• Vertical position is call depth. Callers sit above their callees in pprof's orientation.
• Look for wide plateaus, meaning functions that are wide themselves rather than only because of their children. That's where time is actually spent.

Switch between flat and cumulative in the top view. Flat time is work done in the function itself. Cumulative time includes callees. A function with high cumulative but low flat time is a coordinator, so look inside it.

The usual suspects

After profiling many Go services, the same few problems show up again and again.

1. Allocation pressure

The garbage collector's cost scales with allocation rate. In the allocs profile, look for runtime.mallocgc near the top, then trace up to your code. Common fixes:

Preallocate slices when you know the size:

// Before: grows and copies repeatedly
var ids []string
for _, u := range users {
    ids = append(ids, u.ID)
}

// After: one allocation
ids := make([]string, 0, len(users))
for _, u := range users {
    ids = append(ids, u.ID)
}

Use strings.Builder instead of repeated concatenation, and call Grow if you can estimate the final size.

Reuse short-lived buffers with sync.Pool in hot paths such as encoders:

var bufPool = sync.Pool{New: func() any { return new(bytes.Buffer) }}

func encode(v any) ([]byte, error) {
    buf := bufPool.Get().(*bytes.Buffer)
    buf.Reset()
    defer bufPool.Put(buf)
    if err := json.NewEncoder(buf).Encode(v); err != nil {
        return nil, err
    }
    return bytes.Clone(buf.Bytes()), nil
}

2. Escaping to the heap

Values that outlive their function "escape" to the heap. Ask the compiler which values escape:

go build -gcflags='-m' ./invoice 2>&1 | grep escapes

Returning pointers to small structs, storing values in interfaces, and capturing variables in closures are common causes. Returning small structs by value is often faster than returning pointers.

3. Reflection-heavy serialization

encoding/json uses reflection. If JSON encoding dominates your CPU profile, consider a code-generated encoder for your hottest types, or reduce how much data you serialize in the first place.

4. Hidden fmt costs

fmt.Sprintf in a hot loop allocates and parses the format string every time. For simple conversions, strconv.Itoa and strconv.AppendInt are much cheaper.

5. Lock contention

If CPU usage is low but latency is high, look at the mutex profile. One global lock around a map can serialize your whole service. Options include sharding the map, using sync.RWMutex for read-heavy access, or rethinking the design so goroutines don't share state at all.

Verify with benchstat

After a change, re-run the benchmark and compare:

go test -bench=RenderInvoice -count=10 ./invoice > after.txt
benchstat before.txt after.txt

name             old time/op    new time/op    delta
RenderInvoice-8    48.2µs ± 2%    21.7µs ± 1%   -55.0%
name             old allocs/op  new allocs/op  delta
RenderInvoice-8       412 ± 0%        37 ± 0%   -91.0%

A large delta with a small ± means the improvement is real. If the confidence intervals overlap, you're looking at noise.

Continuous profiling

Some problems only appear under production traffic patterns. Continuous profilers sample every instance at low overhead and let you compare profiles across deploys. That way you can answer "what got slower in yesterday's release?" in minutes.

A disciplined loop

1. Write a benchmark that reproduces the slow path.
2. Profile it and find the widest plateau.
3. Make one change.
4. Confirm with benchstat.
5. Repeat until the service is fast enough, then stop.

That last step matters. Optimizing past your latency budget makes the code harder to read for no user-visible gain.