# Profiling & performance

> Find where a Go service spends CPU and memory with benchmarks, pprof and the execution tracer, then fix the hot spots and verify.

Backend with Go roadmap · Production · 17 min read · https://levelcode.org/roadmaps/go-backend/profiling

When a service is slow or expensive, the worst thing you can do is guess. Engineers are notoriously bad at predicting where time goes, and "optimising" the wrong function adds complexity for nothing. Go ships with excellent tools for measuring instead: benchmarks, the `pprof` profiler, escape analysis and an execution tracer. This lesson shows a measure, change, measure-again workflow on a realistic hot spot, and the handful of fixes that solve most problems.

## Measure first, and measure the right thing

Before profiling code, check that code is the problem. Most slow endpoints are slow because of I/O: a missing index, an N+1 query, a slow downstream call with no timeout. Traces from the [observability lesson](https://levelcode.org/roadmaps/go-backend/observability) show that in seconds: if 180 ms of a 200 ms request is one SQL query, no amount of Go tuning helps.

Profile the code when traces show time spent *inside* your process, when CPU is high, when memory grows, or when you're preparing for a known jump in load. And decide what "better" means first: lower p99 latency, fewer CPU cores, less memory. Each points to a different profile.

## Benchmarks

A benchmark is a test function that measures how long code takes. Here's a function that builds a CSV export line for an order:

```go
func FormatLine(o Order) string {
	s := ""
	s += strconv.FormatInt(o.ID, 10) + ","
	s += o.Customer + ","
	for i, item := range o.Items {
		if i > 0 {
			s += ";"
		}
		s += fmt.Sprintf("%s x%d", item.SKU, item.Qty)
	}
	return s + "," + strconv.FormatInt(o.TotalCents, 10)
}
```

```go
func BenchmarkFormatLine(b *testing.B) {
	o := sampleOrder(20) // an order with 20 line items
	for b.Loop() {
		FormatLine(o)
	}
}
```

`b.Loop()` (Go 1.24) runs the body as many times as needed for a stable measurement, and keeps the compiler from optimising the call away. On older Go versions you'll see `for i := 0; i < b.N; i++`. Run it with memory statistics:

```bash
go test -bench=FormatLine -benchmem -count=10 > old.txt
```

```text
BenchmarkFormatLine-8   	  205874	      5712 ns/op	   7344 B/op	      83 allocs/op
```

Read the three numbers: time per call, bytes allocated per call and allocations per call. 83 allocations to build one line is a strong hint: every `+=` and `Sprintf` creates a new string.

Benchmarks are noisy (CPU frequency scaling, other processes), which is why `-count=10` runs ten samples. Compare old and new versions with `benchstat`, which reports whether a difference is statistically meaningful:

```bash
go install golang.org/x/perf/cmd/benchstat@latest
# ...change the code...
go test -bench=FormatLine -benchmem -count=10 > new.txt
benchstat old.txt new.txt
```

## Fixing allocations

Rewrite with a `strings.Builder` and `strconv` appends, sized up front:

```go
func FormatLine(o Order) string {
	var b strings.Builder
	b.Grow(32 + len(o.Customer) + 16*len(o.Items))
	b.WriteString(strconv.FormatInt(o.ID, 10))
	b.WriteByte(',')
	b.WriteString(o.Customer)
	b.WriteByte(',')
	for i, item := range o.Items {
		if i > 0 {
			b.WriteByte(';')
		}
		b.WriteString(item.SKU)
		b.WriteString(" x")
		b.WriteString(strconv.Itoa(item.Qty))
	}
	b.WriteByte(',')
	b.WriteString(strconv.FormatInt(o.TotalCents, 10))
	return b.String()
}
```

```text
name          old time/op    new time/op    delta
FormatLine-8    5.71µs ± 2%    0.79µs ± 1%   -86.17%  (p=0.000 n=10+10)

name          old alloc/op   new alloc/op   delta
FormatLine-8    7.34kB ± 0%    0.42kB ± 0%   -94.28%  (p=0.000 n=10+10)
```

Your numbers will differ by machine, but the shape won't. Allocation is often the biggest lever in Go: each one costs time to allocate and adds work for the garbage collector later, so fewer allocations speed up the *whole* service, not just this function.

The usual allocation fixes:

- Preallocate slices and maps when you know the size: `make([]T, 0, n)`, `make(map[K]V, n)`.
- Build strings with `strings.Builder` or append to a `[]byte`; avoid `fmt.Sprintf` in hot loops.
- Reuse buffers for short-lived, frequently created objects with `sync.Pool`, but only where a profile shows it matters.
- Avoid converting between `[]byte` and `string` repeatedly; each conversion copies.

### Escape analysis

Whether a value lives on the stack (free) or the heap (an allocation) is decided by the compiler's **escape analysis**. Ask it to explain:

```bash
go build -gcflags='-m' ./... 2>&1 | grep FormatLine
```

```text
./export.go:14:6: can inline FormatLine
./export.go:23:24: item.SKU escapes to heap
```

Values escape when they outlive the function (returned pointers, stored in a global), when they're stored in an interface (`fmt` takes `any`, which is part of why `Sprintf` allocates), or when they're too large or of unknown size at compile time. You don't need to memorise the rules; use `-m` to understand what a profile is telling you.

## pprof in a running service

Benchmarks measure one function. To find *which* function matters in a real service under real load, use the `pprof` profiler. The `net/http/pprof` package registers handlers that capture profiles on demand:

```go
import (
	"net/http"
	_ "net/http/pprof" // registers /debug/pprof/* on http.DefaultServeMux
)

func main() {
	// Serve profiles on a separate, internal-only port.
	go func() {
		log.Println(http.ListenAndServe("localhost:6060", nil))
	}()

	// Your real API uses its own mux on :8080, so profiles aren't exposed publicly.
	api := http.NewServeMux()
	// ...
	log.Fatal(http.ListenAndServe(":8080", api))
}
```

> [!WARNING]
> Never expose `/debug/pprof` on the public listener. Profiles reveal source paths and internals, and a CPU profile request costs CPU. Bind it to localhost or an internal network only.

While the service is under load (use a load generator such as `hey` or `k6`), capture a 30-second CPU profile and open the interactive UI:

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

The web UI offers several views. Start with the **flame graph**: each bar is a function, its width is the share of CPU samples in that function *and everything it calls*, and children stack above their callers. Look for wide bars that belong to your code. The **top** view lists functions by `flat` time (spent in the function itself) and `cum` time (including callees). A function with high `cum` but low `flat` is a coordinator; dig into its children.

Other profiles answer other questions:

| Profile | URL | Answers |
|---|---|---|
| CPU | `/debug/pprof/profile?seconds=30` | Where is CPU time going? |
| Heap | `/debug/pprof/heap` | What is using memory now (`inuse_space`) and what allocates most (`alloc_space`)? |
| Goroutine | `/debug/pprof/goroutine` | How many goroutines exist and where are they blocked? A growing count is a leak. |
| Mutex / block | `/debug/pprof/mutex`, `/block` | Where do goroutines wait on locks and channels? Enable with `runtime.SetMutexProfileFraction` / `SetBlockProfileRate`. |

For a memory leak, take two heap profiles a few minutes apart and diff them: `go tool pprof -base heap1.pb.gz heap2.pb.gz`. What grew between them is your suspect.

You can also profile a benchmark directly, which is handy once you've narrowed things down: `go test -bench=FormatLine -cpuprofile=cpu.out` then `go tool pprof -http=: cpu.out`.

## The execution tracer

Profiles show where time is spent on CPU. They don't show time spent *waiting*: a request that's slow because goroutines queue for a mutex, or because the garbage collector paused, or because only one core is busy. The **execution tracer** records every scheduling event:

```bash
curl -o trace.out 'http://localhost:6060/debug/pprof/trace?seconds=5'
go tool trace trace.out
```

The timeline shows each processor, which goroutine ran when, GC phases and blocking events. Use it when CPU is low but latency is high: that pattern means something is waiting, and the trace shows what.

## Cheap wins once you've measured

- **Garbage collector tuning.** `GOGC` (default 100) trades memory for less GC work; `GOMEMLIMIT` sets a soft memory ceiling, which in containers prevents out-of-memory kills while letting the GC relax when memory is plentiful. Set `GOMEMLIMIT` to roughly 90% of the container limit.
- **Profile-guided optimisation (PGO).** Save a representative production CPU profile as `default.pgo` in your `main` package's directory, and `go build` uses it automatically (Go 1.21+) to inline and optimise hot paths more aggressively. Typical gains are a few percent of CPU, for free.
- **Bound concurrency.** Ten thousand goroutines fighting for a database pool of 20 connections is slower than 20 workers. The worker pools from the concurrency lesson apply.
- **Cache expensive pure work**, such as compiled regular expressions and templates: create them once at startup, not per request.

Always finish with the same benchmark or load test you started with. If the numbers didn't move, revert: a "faster" version that isn't measurably faster is just harder to read.

## Practice

1. Write the original `FormatLine`, a `sampleOrder(n int) Order` helper, and the benchmark. Record `old.txt` with `-count=10`.
2. Rewrite it with `strings.Builder` and compare with `benchstat`.
3. Write `ExportCSV(orders []Order) string` that joins lines with `\n`, and a benchmark for 1,000 orders. Profile it with `-cpuprofile` and `-memprofile` and identify the top allocation site.
4. Add `net/http/pprof` on `localhost:6060` to any HTTP service from this roadmap, put it under load, and find your handler in the CPU flame graph.

**Solution**

```go
func sampleOrder(n int) Order {
	o := Order{ID: 12345, Customer: "ana@example.com", TotalCents: 99_00}
	for i := range n {
		o.Items = append(o.Items, Item{SKU: fmt.Sprintf("SKU-%04d", i), Qty: i%3 + 1})
	}
	return o
}

// ExportCSV writes all lines into one builder instead of concatenating returned strings.
func ExportCSV(orders []Order) string {
	var b strings.Builder
	b.Grow(len(orders) * 256)
	for i, o := range orders {
		if i > 0 {
			b.WriteByte('\n')
		}
		writeLine(&b, o)
	}
	return b.String()
}

// writeLine is FormatLine's body, writing into a caller-provided builder.
func writeLine(b *strings.Builder, o Order) {
	b.WriteString(strconv.FormatInt(o.ID, 10))
	b.WriteByte(',')
	b.WriteString(o.Customer)
	b.WriteByte(',')
	for i, item := range o.Items {
		if i > 0 {
			b.WriteByte(';')
		}
		b.WriteString(item.SKU)
		b.WriteString(" x")
		b.WriteString(strconv.Itoa(item.Qty))
	}
	b.WriteByte(',')
	b.WriteString(strconv.FormatInt(o.TotalCents, 10))
}

func BenchmarkExportCSV(b *testing.B) {
	orders := make([]Order, 1000)
	for i := range orders {
		orders[i] = sampleOrder(20)
	}
	for b.Loop() {
		ExportCSV(orders)
	}
}
```

```bash
go test -bench=ExportCSV -benchmem -cpuprofile=cpu.out -memprofile=mem.out
go tool pprof -top -sample_index=alloc_space mem.out | head
```

A first version that calls `FormatLine` per order and joins the results with `strings.Join` shows two allocation sites at the top: each line's builder, and the joined result. Writing every line into one pre-grown builder removes the per-line strings entirely, leaving about one large allocation per export. That's the general pattern: pass a writer or buffer down instead of returning strings up.

## Key takeaways

- Check traces first: if time is spent in I/O, fix queries and calls, not Go code.
- Benchmark with `b.Loop()`, `-benchmem` and `-count`, and compare versions with `benchstat`.
- Allocations are the most common Go hot spot; preallocate, use builders and buffers, and confirm with escape analysis.
- `net/http/pprof` on an internal port gives CPU, heap, goroutine and lock profiles from a running service; read flame graphs by width.
- Use the execution tracer when CPU is low but latency is high, and consider `GOMEMLIMIT` and PGO once the code is sound.

## Quiz

1. A benchmark reports 5712 ns/op, 7344 B/op, 83 allocs/op for building one short string. What's the most promising first fix?

   A. Run the function in a goroutine
   B. Increase GOGC
   C. Reduce allocations, for example with strings.Builder instead of += and Sprintf
   D. Add sync.Mutex around the function

   **Answer: C.** 83 allocations for one string means repeated concatenation and formatting. Building into one pre-grown buffer removes most of them, which cuts both time and GC work.

2. In a CPU flame graph, what does the width of a function's bar represent?

   A. How many times it was called
   B. Its share of CPU samples, including everything it calls
   C. Its memory usage
   D. Its source file length

   **Answer: B.** Width is cumulative CPU time (samples in the function and its callees). Call counts aren't shown; a function called once can be wide if it's expensive.

3. Requests are slow, but CPU usage is low and the CPU profile shows nothing unusual. Which tool fits next?

   A. The execution tracer, to see what goroutines are waiting on
   B. A heap profile
   C. Escape analysis with -gcflags=-m
   D. Increasing -count on benchmarks

   **Answer: A.** Low CPU with high latency means time is spent waiting: locks, channels, GC pauses or I/O. The tracer (and block/mutex profiles) show waiting; CPU profiles only show running.

4. Where should /debug/pprof be served in production?

   A. On the public API port, behind the same auth as the API
   B. Nowhere; pprof is only for development
   C. On a public port with a hard-to-guess path
   D. On a separate listener bound to localhost or an internal network

   **Answer: D.** Profiles expose internals and cost CPU to capture. Keeping them on an internal-only listener lets you profile production safely.