skip to content
Alvin Lucillo

Basic pprof

/ 2 min read

In the example below, pprof tool was used to check the CPU profile of a benchmark, particularly for CountAllowedEventsLinear function, tested by BenchmarkCountAllowedEvents. For now, we see the “linear” version, but later on, in upcoming daily entries, we will see an improved version.

Notice that the lookup performs iteration for the same lookup reference (allowedNames) for every event name. From this, we could sense there might be a perform issue and an opportunity to improve this.

func CountAllowedEventsLinear(eventNames, allowedNames []string) int {
	count := 0
	for _, name := range eventNames {
		if slices.Contains(allowedNames, name) {
			count++
		}
	}
	return count
}
func BenchmarkCountAllowedEvents(b *testing.B) {

	allowedNames := make([]string, 1_000)
	for i := range allowedNames {
		allowedNames[i] = fmt.Sprintf("event.%04d", i)
	}

	eventNames := make([]string, 2_000)
	for i := range eventNames {
		eventNames[i] = allowedNames[len(allowedNames)-1]
	}

	b.Run("implementation=linear", func(b *testing.B) {
		var count int
		b.ReportAllocs()
		for b.Loop() {
			count = CountAllowedEventsLinear(eventNames, allowedNames)
		}
		sinkAllowedCount = count
	})
}

The command below runs the benchmark test and creates a CPU profile.

go test -run '^$' \
  -bench '^BenchmarkCountAllowedEvents$/^implementation=linear$' \
  -benchtime=5s \
  -cpuprofile=/tmp/codec01-allowlist-linear-cpu.pprof

goos: linux
goarch: arm64
pkg: codec01
BenchmarkCountAllowedEvents/implementation=linear-12                1544           3907842 ns/op               0 B/op          0 allocs/op
PASS
ok      codec01 6.040s

The CPU profile above is analyzed by pprof tool. flat values refer to the specific function/operation, and cum values are cumulative values that include downstream calls.

The resutl shows that the operation took ~6s, with 56% consumed by slices.Index and 42.45% by runtime.memequal. The profile shows which process contribute to the overall process time.

go tool pprof -top \
  /tmp/codec01-allowlist-linear-cpu.pprof 
File: codec01.test
Build ID: b577d07ab1e87fb7010e13f74ca1ed5b56d03c8a
Type: cpu
Time: 2026-10-24 21:56:29 PST
Duration: 6.04s, Total samples = 6.03s (99.89%)
Showing nodes accounting for 5.99s, 99.34% of 6.03s total
Dropped 12 nodes (cum <= 0.03s)
      flat  flat%   sum%        cum   cum%
     3.40s 56.38% 56.38%      5.96s 98.84%  slices.Index[go.shape.[]string,go.shape.string] (inline)
     2.56s 42.45% 98.84%      2.56s 42.45%  runtime.memequal
     0.03s   0.5% 99.34%      5.99s 99.34%  codec01.CountAllowedEventsLinear (inline)
         0     0% 99.34%         6s 99.50%  codec01.BenchmarkCountAllowedEvents.func1
         0     0% 99.34%      5.96s 98.84%  slices.Contains[go.shape.[]string,go.shape.string] (inline)
         0     0% 99.34%         6s 99.50%  testing.(*B).run1.func1
         0     0% 99.34%         6s 99.50%  testing.(*B).runN