Benchmarks and profiling · Go: Zero to Production

Go ships a benchmark runner in the same testing package as your tests. That matters more than it sounds: measuring is so cheap that "I think this is faster" becomes "here are the numbers" in about ninety seconds.

A benchmark

Benchmarks live in _test.go files alongside your tests:

package strutil

import (
    "strings"
    "testing"
)

func ConcatPlus(parts []string) string {
    out := ""
    for _, p := range parts {
        out += p
    }
    return out
}

func ConcatBuilder(parts []string) string {
    var b strings.Builder
    for _, p := range parts {
        b.WriteString(p)
    }
    return b.String()
}

var parts = strings.Split(strings.Repeat("word ", 1000), " ")

func BenchmarkConcatPlus(b *testing.B) {
    for i := 0; i < b.N; i++ {
        ConcatPlus(parts)
    }
}

func BenchmarkConcatBuilder(b *testing.B) {
    for i := 0; i < b.N; i++ {
        ConcatBuilder(parts)
    }
}

Same rules as tests, three differences: the name starts with Benchmark, it takes b *testing.B, and the body loops b.N times.

You never choose b.N. The runner starts small and increases it until the measurement takes long enough to be statistically meaningful.

$ go test -bench=. -benchmem
BenchmarkConcatPlus-8        1206     985431 ns/op    5044212 B/op    1000 allocs/op
BenchmarkConcatBuilder-8    58122      20516 ns/op      24576 B/op      12 allocs/op

Read a line as: name-GOMAXPROCS, iterations run, nanoseconds per operation, bytes allocated per operation, allocations per operation.

The strings.Builder version is ~48× faster and allocates 200× less. That's module 4's advice, measured — and it's the kind of thing worth measuring rather than believing.

Always pass -benchmem. Allocation counts are usually the thing you can actually fix.

Seeing the same comparison here

The lesson boxes can't run go test -bench, but they can time the two approaches directly:

package main

import (
    "fmt"
    "strings"
    "time"
)

func concatPlus(parts []string) string {
    out := ""
    for _, p := range parts {
        out += p
    }
    return out
}

func concatBuilder(parts []string) string {
    var b strings.Builder
    for _, p := range parts {
        b.WriteString(p)
    }
    return b.String()
}

func main() {
    parts := make([]string, 10000)
    for i := range parts {
        parts[i] = "word"
    }

    start := time.Now()
    a := concatPlus(parts)
    plusTime := time.Since(start)

    start = time.Now()
    c := concatBuilder(parts)
    builderTime := time.Since(start)

    fmt.Println("same result:", a == c, "length:", len(a))
    fmt.Println("Builder was faster:", builderTime < plusTime)
    fmt.Println("roughly how many times faster:", int(plusTime/builderTime))
}

The ratio varies with the machine, but the direction never does: += in a loop copies the whole accumulated string every iteration, so its cost grows quadratically.

Benchmarking correctly

Three ways to get a meaningless number:

// 1. The compiler deletes work whose result is unused.
func BenchmarkBad(b *testing.B) {
    for i := 0; i < b.N; i++ {
        Fib(20)                 // result discarded — may be optimised away
    }
}

var sink int                    // package-level: can't be optimised away

func BenchmarkGood(b *testing.B) {
    var r int
    for i := 0; i < b.N; i++ {
        r = Fib(20)
    }
    sink = r
}

// 2. Setup counted inside the measurement.
func BenchmarkWithSetup(b *testing.B) {
    data := buildHugeSlice()    // expensive
    b.ResetTimer()              // start counting HERE
    for i := 0; i < b.N; i++ {
        Process(data)
    }
}

// 3. Per-iteration setup, excluded properly.
func BenchmarkPerIter(b *testing.B) {
    for i := 0; i < b.N; i++ {
        b.StopTimer()
        input := freshInput()
        b.StartTimer()
        Process(input)
    }
}

Also useful: -benchtime=5s for longer, steadier runs, and -count=10 to get several samples. Run them through benchstat, which reports whether a difference is statistically real rather than noise:

$ go test -bench=Concat -count=10 > old.txt
# ...make your change...
$ go test -bench=Concat -count=10 > new.txt
$ benchstat old.txt new.txt

Comparing single runs is how people convince themselves of improvements that don't exist.

Profiling: find the hot spot first

Benchmarks tell you how long. Profiles tell you where.

$ go test -bench=. -cpuprofile=cpu.out -memprofile=mem.out
$ go tool pprof cpu.out
(pprof) top10
(pprof) list MyFunction
(pprof) web            # opens an SVG call graph

For a running server, import net/http/pprof and profile it live:

import _ "net/http/pprof"      // registers handlers on the default mux

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

$ go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
$ go tool pprof http://localhost:6060/debug/pprof/heap
$ go tool pprof http://localhost:6060/debug/pprof/goroutine   # leak hunting

That blank-identifier import (_ "net/http/pprof") is imported purely for its side effect: the package's init registers the handlers. Never expose that port publicly.

The goroutine profile is the one that finds the leaks from module 9 — if the count climbs steadily and never falls, something isn't exiting.

The optimisation order

Make it work. Correct beats fast.
Write a benchmark. You cannot improve what you don't measure.
Profile. The bottleneck is very rarely where you'd guess.
Fix the top item only. Then re-measure — the profile has changed.
Stop when it's fast enough.

The wins that actually show up, in rough order of frequency:

Fewer allocations. Pre-size slices and maps, reuse buffers, use strings.Builder. This is most of it.
A better algorithm. An O(n²) loop over a slice becomes O(n) with a map. No micro-optimisation competes with that.
Avoid unnecessary copying of large structs.
Concurrency, last — it's the one that adds bugs.

package main

import (
    "fmt"
    "time"
)

func containsSlice(items []string, want string) bool {
    for _, v := range items {
        if v == want {
            return true
        }
    }
    return false
}

func main() {
    const n = 4000
    items := make([]string, n)
    for i := 0; i < n; i++ {
        items[i] = fmt.Sprintf("item-%d", i)
    }

    start := time.Now()
    found := 0
    for i := 0; i < n; i++ {
        if containsSlice(items, fmt.Sprintf("item-%d", i)) {
            found++
        }
    }
    sliceTime := time.Since(start)

    index := make(map[string]struct{}, n)
    for _, v := range items {
        index[v] = struct{}{}
    }

    start = time.Now()
    found2 := 0
    for i := 0; i < n; i++ {
        if _, ok := index[fmt.Sprintf("item-%d", i)]; ok {
            found2++
        }
    }
    mapTime := time.Since(start)

    fmt.Println("both found:", found, found2)
    fmt.Println("map lookup was faster:", mapTime < sliceTime)
}

n² string comparisons versus n hash lookups. Building the map costs one pass and pays for itself immediately — this single change is the most common real speedup in Go code.

Your turn

Time the pre-sized slice against the unsized one and report which allocated less work:

same length: true
pre-sizing was not slower: true

package main

import (
    "fmt"
    "time"
)

func main() {
    const n = 100000

    start := time.Now()
    var unsized []int
    // append 0..n-1 to unsized
    unsizedTime := time.Since(start)

    start = time.Now()
    sized := make([]int, 0, n)
    // append 0..n-1 to sized
    sizedTime := time.Since(start)

    fmt.Println("same length:", len(unsized) == len(sized))
    fmt.Println("pre-sizing was not slower:", sizedTime <= unsizedTime*2)
}

package main

import (
    "fmt"
    "time"
)

func main() {
    const n = 100000

    start := time.Now()
    var unsized []int
    for i := 0; i < n; i++ {
        unsized = append(unsized, i)
    }
    unsizedTime := time.Since(start)

    start = time.Now()
    sized := make([]int, 0, n)
    for i := 0; i < n; i++ {
        sized = append(sized, i)
    }
    sizedTime := time.Since(start)

    fmt.Println("same length:", len(unsized) == len(sized))
    fmt.Println("pre-sizing was not slower:", sizedTime <= unsizedTime*2)
}

Next: the tools around the code — modules, formatting and vetting.