JavaRush /Courses /Go SELF /pprof in Go: CPU and memory profiles, go tool pprof, read...

pprof in Go: CPU and memory profiles, go tool pprof, reading top and hotspots

Go SELF
Level 71, Lesson 4
Available

1. Introduction to pprof

If a benchmark is a stopwatch, then pprof is a very picky accountant: it does not just say “the operation took 120 ms”, it tries to show which functions those milliseconds “burned” in. In Go, pprof lives as the go tool pprof tool, which interprets and displays program profiles. The basic scenario is simple: you have a binary and a profile file, and you feed them to pprof.

It is important to set expectations correctly: pprof does not promise “to make it faster”; it promises “to show where it hurts”. And you do the fixing: remove unnecessary allocations, redesign the hot loop, use a more suitable data structure. (Yes, sometimes it is “fixed” by removing a single fmt.Sprintf inside a loop—like finding a small pebble in your shoe after a two-hour walk.)

2. Capturing profiles via go test

The nicest part: to get started, you do not need to wire profiling into main and write any helper code. For tests and benchmarks, support is already built into go test. There are profiling flags that write profiles suitable for analysis with go tool pprof.

The minimal “reference” command looks like this: you run benchmarks and, at the same time, ask to save CPU and memory profiles into files. An example from the runtime/pprof documentation:

go test -bench . -cpuprofile cpu.prof -memprofile mem.prof

Two subtle (but very practical) points matter here.

First: the profiles are written for the run that actually executed. If the benchmark is too short, the profile can be “noisy” and almost useless.

Second: go test can rewrite flags and control how the test binary is executed, and also profiling flags (except coverage) usually leave the test binary nearby so it can be used when analyzing the profile. This is useful because pprof often wants to see both the profile and the binary so it can show functions and lines of code.

CPU profile and -cpuprofile

A CPU profile answers the question “where did the CPU time go”. In Go, CPU profiling is implemented as sampling: while the program runs, about 100 times per second it “stops for a micro-moment” and records the stack of the currently executing goroutine (think: “takes a snapshot of where we are”). That is why a CPU profile is statistical: it does not guarantee perfect accuracy down to the last nanosecond, but it is excellent at showing hot spots.

To make this concrete, let’s tie it to our training app. Suppose we have a list of tasks and we want to render them nicely into a table for a CLI (we have done tabular output before, so now we will use a simplified string format). First, we will implement deliberately “not very clever” rendering—using fmt.Sprintf in a loop. Yes, it is like hammering nails with a microscope: technically possible, but do not complain about the cost later.

package taskfmt

import "fmt"

type Task struct {
	ID    int
	Title string
	Done  bool
}

func FormatLineSprintf(t Task) string {
	return fmt.Sprintf("%d\t%v\t%s\n", t.ID, t.Done, t.Title)
}

So far it looks innocent. But if there are thousands of such lines and this is in a “hot” path, fmt.Sprintf can become quite an expensive habit (both CPU- and memory-wise). We do not “guess by vibes”—we profile it.

Memory profile and -memprofile

A memory profile (in today’s minimum: a heap profile) answers the question “where do we allocate memory and/or where is it retained”. This is especially important in Go, because extra allocations are not only “we used more memory”, but also potentially extra work for the GC. And GC, as you already suspect, is not free (it just tries to be “cheap enough”).

go test can write a memory profile to a file via -memprofile, and there is also the hint that pprof has allocation presentation modes (for example, by object count or by size)—that is on the pprof side as a visualization tool.

To have an example, let’s add another function: we will assemble all task output into one big string (for a CLI, that is fine—we print one chunk to stdout). First we do it “straightforwardly”—by concatenating strings in a loop. This is a classic: it works, but at large scale it can create many temporary strings.

package taskfmt

func FormatAllConcat(tasks []Task) string {
	out := ""
	for _, t := range tasks {
		out += FormatLineSprintf(t)
	}
	return out
}

If there are many tasks, out += ... often means: “create a new string, copy the old one, append the new part”. Sometimes the compiler helps, but in the general case it is a candidate for extra allocations. And this is where a memory profile is often especially illustrative: it shows who exactly became a garbage factory.

Benchmark for a reproducible load

We need a reproducible load scenario. A benchmark is ideal: it is controlled, repeatable, and does not require “clicking buttons manually”. In *_test.go we will add BenchmarkFormatAllConcat. Here we will also use the “sink variable” trick: the result must be written somewhere so the compiler does not decide that the computation “is not needed by anyone” and can be eliminated.

package taskfmt

import (
	"strconv"
	"testing"
)

var sink string

func BenchmarkFormatAllConcat(b *testing.B) {
	tasks := make([]Task, 1000)
	for i := range tasks {
		tasks[i] = Task{ID: i + 1, Title: "task " + strconv.Itoa(i+1)}
	}
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		sink = FormatAllConcat(tasks)
	}
}

Now we have a “playground” where both CPU and memory will show themselves clearly enough. And then the best part begins: we capture profiles and read them.

3. Profile analysis in go tool pprof

The basic use of pprof is very simple: go tool pprof binary profile. That is, typically you give the tool a binary and a profile file.

When we profile tests/benchmarks, the process still splits into two levels.

At the first level, we ask go test to write a profile, for example like this (as a reminder of the command shape):

go test -bench . -cpuprofile cpu.prof -memprofile mem.prof

At the second level, we open the profile in pprof. A very common scenario is to open the CPU profile together with the test binary (which go test may leave nearby) so that pprof shows function names and lets you jump to source lines. The general idea stays the same: go tool pprof <binary> <profile>.

When pprof starts, it enters interactive mode: you will see the (pprof) prompt and then you type commands. The first commands that almost always give real value: top, top -cum, and sometimes list <func>.

How to read top and top -cum: hotspots, flat and cum

The word “hotspot” here means something simple: a place that contributes substantially to the cost. In a CPU profile, it is a place where “CPU time is burning”. In a memory profile, it is a place where “memory is burning” (a lot is allocated or a lot is retained).

The topN command (or just top, depending on the mode) shows functions with the largest contribution. The classic Go profiling article notes that top is sorted by the function’s “self time”, and sorting by accumulated time is available via -cum (cumulative).

So that the output does not look like ancient runes, let’s break down the meaning of the columns in a small table (names can differ slightly, but the meaning is usually the same):

Column How to read it Intuitive meaning
flat
“how much time or memory is directly in this function” the function itself “eats” the resource
cum
“how much time or memory is in this function and everything it calls” the function is an “entry into the grinder”
%
share of the total how important this is in the overall picture

Now for the practical reading logic. If, at the top of top, you see runtime.* or fmt.*, it does not mean “you should optimize the runtime”. It means your code forced the runtime or fmt to do a lot of work. Often the right next step is to find your function that calls fmt.Sprintf in a loop, and rewrite that.

Mini pprof session: top, top -cum, list

The interactivity of pprof initially looks like “yet another console”, but in practice it is very convenient: you can quickly “zoom in” on a problem. For example, the logic might look like this (commands are an illustration of a scenario, not an “assignment”):

go tool pprof <binary> cpu.prof
(pprof) top
(pprof) top -cum
(pprof) list FormatAllConcat

Why this works. top shows candidates for hotspots. top -cum helps find “parent” functions through which a lot of time flows. And list shows annotated source: which lines inside the function were hit more often by samples. This exact “topN and then -cum” approach is described in the official article: topN shows the top by samples, and -cum resorts by cumulative time.

And yes, pprof has more commands and options than the average video game, but this basic set already gives 80% of the value.

4. Improvements based on the profile and correct interpretation

Optimizing for the sake of optimizing is a bad habit (like drinking an energy drink so you can sleep). But profile-driven optimization is normal engineering: we change code where it is actually hot.

In our example, the suspects are already obvious: string concatenation in a loop and fmt.Sprintf. The most typical fix for “build a big string from small ones” is strings.Builder. We already know this tool from the topic of strings and the strings package, so now we just apply it where it matters.

package taskfmt

import "strings"

func FormatAllBuilder(tasks []Task) string {
	var b strings.Builder
	for _, t := range tasks {
		b.WriteString(FormatLineSprintf(t))
	}
	return b.String()
}

This can already reduce the number of intermediate strings. But we still call fmt.Sprintf inside the loop. If the profiles show that a significant share goes into fmt, then the next step is to stop using Sprintf in the hot path and write to the builder more directly (for example, via strconv.AppendInt into a []byte), but that is more subtle and not always needed right away in a learning project. The key point is different: pprof helps you make decisions not at the level of “I feel like it”, but at the level of “here is the contribution”.

CPU vs memory: how not to mix up what profiles mean

When you first see two profiles, it is tempting to think they are “about the same thing”. In practice, they answer different questions.

A CPU profile shows where the program actually executed (based on execution samples).

A memory profile helps you see where allocations happen or heap usage occurs (and therefore where GC pressure may grow).

A very common scenario: a CPU hotspot and a memory hotspot can be in different places. For example, CPU time goes into parsing and comparing strings, while memory blows up in logging or formatting. Or the other way around: CPU looks “fine”, but memory allocation is insane, GC starts running more often, and as a result CPU also starts burning—but secondarily.

So the right habit is: if you care about “slow”, start with CPU. If you care about “uses too much memory” or “GC is noisy”, look at memory. If you care about everything at once—congratulations, you are almost in production.

Why it matters that go tool pprof matches your Go version

For dessert—an important compatibility note. The Go sources explicitly say that “what is guaranteed to work is what ships with a specific Go release”: that is, go tool pprof from the Go distribution is tested for compatibility with profiles produced by programs of the same version.

This does not mean “you cannot do it differently”. It means that if you start installing a random pprof from the internet (or pull github.com/google/pprof directly) and hit weird issues, it will not be “Go broke”, it will be “you left the recommended path”. For a learning project, sticking to go tool pprof is the calmest route.

5. Common mistakes when working with pprof

Mistake #1: capturing a profile on a run that is too short and being surprised by noise.
CPU profiling in Go is sampling. If your benchmark ran “almost instantly”, the statistics will be sparse, and top may show random spikes. In such cases, it usually helps to make the load run longer (for example, so the benchmark takes a noticeable amount of time), and only then compare profiles.

Mistake #2: measuring something other than what you think because setup ended up in the profile.
If inside the measured loop you create test data, read files, print logs, or do rand.New(...), the profile will honestly show exactly that. And then the classic begins: “pprof says my hotspot is strconv.Itoa, but I optimized sorting!” So separate data preparation from the measured part as strictly as we already did in benchmarks.

Mistake #3: opening a profile without the right binary and losing context.
pprof is especially useful when it sees the binary: then it can map samples to functions and lines of code. The bonus is that go test, for profiles (except coverage), usually leaves the test binary so you can analyze profiles together with it. If the binary does not match (different build, different version, different code), the output can become less clear.

Mistake #4: getting stuck on runtime.* in top and trying to “optimize the runtime”.
When the top of the list is runtime.mallocgc or something from fmt, it is almost always a symptom of your code: many allocations, lots of formatting, too many conversions, poor data structures. The fix is usually not patching the runtime, but reducing pressure on it: fewer temporary objects, a simpler loop, more careful string handling.

Mistake #5: looking only at top (flat) and missing the “entry point of the problem”.
Sometimes a function itself does almost no work, but it triggers a chain of expensive operations. In top by flat it may be low, but in top -cum it will be high. The -cum mode is exactly what you need to see “who the main cost flows through”. This approach (and the meaning of cumulative sorting) is shown in the official Go profiling article.

1
Task
Go SELF, level 71, lesson 4
Locked
First profiles
First profiles
1
Task
Go SELF, level 71, lesson 4
Locked
Call chain
Call chain
1
Task
Go SELF, level 71, lesson 4
Locked
String and the heap
String and the heap
1
Survey/quiz
Concurrent tests, 71 level, 4 lesson
Unavailable
Concurrent tests
Concurrent tests
Comments
TO VIEW ALL COMMENTS OR TO MAKE A COMMENT,
GO TO FULL VERSION