Read a pprof Flame Graph in Go Without Guessing Wrong

A flame graph is the picture most people associate with profiling, and the picture most people misread. It looks like a chart where taller means slower, and it is not. This article builds a flame graph from a real Go CPU profile without any graphics tools, as indented text from the folded stack format, so the numbers behind each box are visible. Then it uses the numbers to state the rules for reading the picture, including the one that surprises people most: in an ordinary Go program, a lot of the graph is not your code.

It builds on CPU profiling with pprof, where the profile is captured and read as a table, and leads into heap profiles and allocation profiles, which use the same graph. The cornerstone is profiling and speeding up Go.

What a flame graph encodes

Each sample in a CPU profile is a stack of function calls, from runtime.main at the bottom to whatever was running at the top. A flame graph merges samples that share a prefix. Reading it:

• Each box is a function in a particular call path. The same function called from two places appears as two boxes.
• Width is the number of samples, so the share of time, including everything the function called. A box 40 percent wide was on the stack for 40 percent of the samples.
• Height is call depth, which says nothing about time. A tall narrow tower is a deep call chain that did little.
• The order left to right is arbitrary. Classic flame graphs sort alphabetically so identical stacks merge; pprof's flame view sorts by width. Position tells you nothing, only width and nesting do.
• Colour is decoration. It rarely means anything.
• Self time is the part of a box not covered by the boxes above it. A box with a visible flat top (a plateau) is where instructions ran. A box fully covered by children only called other functions.

The pprof web UI draws it for you (go tool pprof -http=:8081 prog cpu.pprof, view "Flame Graph"). Tools like Brendan Gregg's flamegraph.pl and speedscope read the folded stack text format, which is what the lab produces.

The experiment

The program runs a small three step workload under the CPU profiler: parse converts numbers to strings and back, render formats lines with fmt.Sprintf, and compress runs deflate on repeated text. It then parses its own profile with the github.com/google/pprof/profile package, folds the stacks, and draws a text flame graph.

package main

import (
	"bytes"
	"compress/flate"
	"fmt"
	"io"
	"runtime/pprof"
	"sort"
	"strconv"
	"strings"
	"time"

	"github.com/google/pprof/profile"
)

var sink int

func parse(n int) {
	for i := 0; i < n; i++ {
		v, _ := strconv.Atoi(strings.TrimSpace("  " + strconv.Itoa(i) + "  "))
		sink += v
	}
}

func format(n int) {
	for i := 0; i < n; i++ {
		sink += len(fmt.Sprintf("%08d|%-12s|%6.2f", i, "gopher", float64(i)/7))
	}
}

func render(n int) { format(n) }

func compress(n int) {
	data := bytes.Repeat([]byte("the quick brown fox jumps over the lazy dog "), 64)
	for i := 0; i < n; i++ {
		w, _ := flate.NewWriter(io.Discard, flate.BestSpeed)
		w.Write(data)
		w.Close()
	}
}

func handle() {
	parse(8000000)
	render(4000000)
	compress(12000)
}

type node struct {
	name     string
	total    int64
	self     int64
	children map[string]*node
}

func (n *node) child(name string) *node {
	if n.children == nil {
		n.children = map[string]*node{}
	}
	c := n.children[name]
	if c == nil {
		c = &node{name: name}
		n.children[name] = c
	}
	return c
}

func main() {
	var buf bytes.Buffer
	pprof.StartCPUProfile(&buf)
	start := time.Now()
	handle()
	pprof.StopCPUProfile()
	_ = start

	prof, err := profile.Parse(&buf)
	if err != nil {
		panic(err)
	}
	cpu := 1 // sample types: samples/count, cpu/nanoseconds
	root := &node{name: "all"}
	folded := map[string]int64{}
	var total int64
	for _, s := range prof.Sample {
		v := s.Value[cpu]
		total += v
		// Locations are leaf first; each location may hold inlined calls, innermost first.
		var stack []string
		for i := len(s.Location) - 1; i >= 0; i-- {
			lines := s.Location[i].Line
			for j := len(lines) - 1; j >= 0; j-- {
				stack = append(stack, lines[j].Function.Name)
			}
		}
		folded[strings.Join(stack, ";")] += v
		n := root
		n.total += v
		for _, f := range stack {
			n = n.child(f)
			n.total += v
		}
		n.self += v
	}

	fmt.Printf("samples: %d, cpu: %d ms\n\n", len(prof.Sample), total/1e6)
	fmt.Println("== folded stacks, the input format of flame graph tools (top 5 by weight)")
	type kv struct {
		k string
		v int64
	}
	var fs []kv
	for k, v := range folded {
		fs = append(fs, kv{k, v})
	}
	sort.Slice(fs, func(i, j int) bool { return fs[i].v > fs[j].v })
	for _, e := range fs[:5] {
		parts := strings.Split(e.k, ";")
		if len(parts) > 4 {
			parts = append([]string{"..."}, parts[len(parts)-3:]...)
		}
		fmt.Printf("%6d ms  %s\n", e.v/1e6, strings.Join(parts, ";"))
	}

	fmt.Println("\n== the same data as a text flame graph (width is share of all samples, depth is call depth)")
	var walk func(n *node, depth int)
	walk = func(n *node, depth int) {
		var kids []*node
		for _, c := range n.children {
			kids = append(kids, c)
		}
		sort.Slice(kids, func(i, j int) bool { return kids[i].total > kids[j].total })
		for _, c := range kids {
			share := float64(c.total) / float64(total) * 100
			if share < 4 || depth > 5 {
				continue
			}
			bar := strings.Repeat("#", int(share/2)+1)
			fmt.Printf("%s%-34s %5.1f%% total %5.1f%% self %s\n", strings.Repeat("  ", depth), c.name, share, float64(c.self)/float64(total)*100, bar)
			walk(c, depth+1)
		}
	}
	walk(root, 0)
}

set -e
go mod tidy > /dev/null 2>&1
go run .

samples: 143, cpu: 2950 ms

== folded stacks, the input format of flame graph tools (top 5 by weight)
   310 ms  ...;runtime.notesleep;runtime.semasleep;runtime.pthread_cond_wait
   280 ms  ...;runtime.sysUsed;runtime.sysUsedOS;runtime.madvise
   200 ms  ...;strconv.bigFtoa;strconv.(*decimal).Shift;strconv.rightShift
   180 ms  ...;runtime.startTheWorldWithSema;runtime.netpoll;runtime.kevent
   130 ms  ...;main.format;fmt.Sprintf;fmt.(*pp).doPrintf

== the same data as a text flame graph (width is share of all samples, depth is call depth)
runtime.main                        40.3% total   0.0% self #####################
  main.main                           40.3% total   0.0% self #####################
    main.handle                         40.3% total   0.0% self #####################
      main.render                         25.4% total   0.0% self #############
        main.format                         25.4% total   0.0% self #############
          fmt.Sprintf                         24.4% total   0.3% self #############
      main.parse                           9.5% total   0.0% self #####
        strconv.Itoa                         5.8% total   0.0% self ###
          strconv.FormatInt                    5.8% total   0.3% self ###
      main.compress                        5.4% total   0.0% self ###
        compress/flate.NewWriter             4.7% total   0.0% self ###
          compress/flate.(*compressor).init    4.7% total   0.0% self ###
runtime.systemstack                 33.9% total   0.0% self #################
  runtime.(*mheap).alloc.func1        11.2% total   0.0% self ######
    runtime.(*mheap).allocSpan          11.2% total   0.0% self ######
      runtime.sysUsed                      9.5% total   0.0% self #####
        runtime.sysUsedOS                    9.5% total   0.0% self #####
          runtime.madvise                      9.5% total   9.5% self #####
  runtime.gcStart.func4                6.4% total   0.0% self ####
    runtime.startTheWorldWithSema        6.4% total   0.0% self ####
      runtime.netpoll                      6.1% total   0.0% self ####
        runtime.kevent                       6.1% total   6.1% self ####
  runtime.gcBgMarkWorker.func2         4.4% total   0.0% self ###
    runtime.gcDrainMarkWorkerDedicated   4.1% total   0.0% self ###
      runtime.gcDrain                      4.1% total   0.0% self ###
runtime.mcall                       15.9% total   0.0% self ########
  runtime.park_m                      15.3% total   0.0% self ########
    runtime.schedule                    14.9% total   0.3% self ########
      runtime.findRunnable                13.2% total   0.3% self #######
        runtime.stopm                       10.5% total   0.0% self ######
          runtime.mPark                       10.5% total   0.0% self ######
runtime.gcBgMarkWorker               6.4% total   0.0% self ####
  runtime.systemstack                  6.1% total   0.0% self ####
    runtime.gcBgMarkWorker.func2         6.1% total   0.0% self ####
      runtime.gcDrainMarkWorkerDedicated   6.1% total   0.0% self ####
        runtime.gcDrain                      6.1% total   0.3% self ####

The pprof module is pinned to a pseudo version from August 2025. The newest commits require a newer Go toolchain than the 1.25 used here, so the pin is part of the lab, and in your own tool use a version that your Go can build.

The folded stacks

The first output is the input format of every flame graph tool: one line per distinct stack, frames separated by semicolons, with a count. The program prints the five heaviest (shortened to the last three frames):

• 310 ms ...;runtime.notesleep;runtime.semasleep;runtime.pthread_cond_wait threads sleeping
• 280 ms ...;runtime.sysUsed;runtime.sysUsedOS;runtime.madvise memory returned to and taken from the OS
• 200 ms ...;strconv.bigFtoa;strconv.(*decimal).Shift;strconv.rightShift slow float formatting
• 180 ms ...;runtime.startTheWorldWithSema;runtime.netpoll;runtime.kevent the scheduler polling for events
• 130 ms ...;main.format;fmt.Sprintf;fmt.(*pp).doPrintf your code's formatting

Five lines, and four of them are runtime internals. That is the first lesson, and the text graph below makes it concrete.

The text flame graph

The program prints the call tree with each frame's total and self share of all samples, with an indentation for depth and a bar for width. The part under main.main:

• main.handle 40.3 percent total, 0.0 self - main.render 25.4 percent, main.format 25.4, fmt.Sprintf 24.4 - main.parse 9.5 percent, with strconv.Itoa 5.8 - main.compress 5.4 percent, with compress/flate.NewWriter 4.7

and the other roots:

• runtime.systemstack 33.9 percent: allocator work (runtime.(*mheap).alloc.func1 11.2, down to runtime.madvise 9.5 self), GC start (gcStart.func4 6.4) and mark workers (4.4).
• runtime.mcall 15.9 percent: park_m, schedule, findRunnable, stopm, mPark. These are idle threads parking.
• runtime.gcBgMarkWorker 6.4 percent: the garbage collector's background workers.

What the numbers teach

Your code is not the whole picture. main.handle is 40 percent. The other 60 percent is the runtime. A first reading of the graph as "60 percent of my program is in runtime.*, something is broken" is wrong. The profile counts CPU time on all threads. On a 10 core machine a mostly single threaded program has idle threads (the scheduler parking and waking them, 15.9 percent), a garbage collector running on other cores (6.4 percent) and the allocator calling the OS (33.9 percent under systemstack). Those costs are real but they are consequences: allocation and parking happen because the program allocates and because Go runs on several threads.

What to do with the 60 percent:

• Focus on the part you control. pprof -focus main.handle restricts the graph to samples that include main.handle, so the percentages are relative to your code's share.
• Ignore idle frames. -ignore 'runtime.(findRunnable|mPark|stopm|schedule)' removes the parking, so the picture is about work.
• Treat allocator and GC frames as a hint, not a verdict. A wide runtime.mallocgc under your function means the function allocates a lot. Look at the allocation profile to find where (allocation profiles).

Total is not cost, self is. main.handle has 40.3 percent total and 0.0 self: it only calls. main.render and main.format likewise, with all of their time inside fmt.Sprintf. The plateaus are the places where instructions ran: runtime.madvise at 9.5 percent self and runtime.kevent at 6.1. In a real flame graph you find wide boxes first (they own time), then follow down to the plateau (it spends it).

The widest box under your code is the target. fmt.Sprintf at 24.4 percent is the biggest single thing in main.handle, and the folded stack shows part of why: strconv.bigFtoa and rightShift at 200 ms is the slow path of formatting floating point values with %6.2f for values that the fast path cannot handle. That detail is two frames below the call you wrote, and it is what separates "use strconv.AppendFloat in a buffer" from "formatting is slow". Follow the tower down.

Narrow is not nothing. main.compress at 5.4 percent is small here, and a function you call a million times from many places can be small in each box and large in total. Pprof's -top merges by function, and the flame graph splits by call path, so use both. Another case is deep recursion, where the same function appears many levels deep and the graph shows a tall tower of identical names. The width of the bottom box is its total.

Using the graph to decide

A simple procedure with a flame graph, in order:

1. Find the widest boxes under your own code. Ignore the runtime roots at first.
2. Descend each to its plateau. Ask whether the leaf is something you can avoid, batch or replace.
3. Check how the same leaf appears elsewhere. A leaf can be cheap per call and everywhere. -top shows its merged total.
4. Compare before and after. go tool pprof -http=:8081 -diff_base old.pprof new.pprof shows a differential flame graph: boxes that shrank or grew.
5. Confirm with a benchmark. A profile points at where, a benchmark proves how much (benchmarks).

Reading production flame graphs

A service profile is wider and flatter than this toy. Expect HTTP serving frames, encoding and decoding, database calls, and a big block of runtime. Two habits help. Look at the shape: one dominant tower says "fix this one thing", while a flat skyline of many similar boxes says the time is spread out and the lever is architectural (caching, batching, fewer calls). And look at the colours of the runtime: a wide gcBgMarkWorker plus wide mallocgc says the heap is under pressure, and the right tool is the heap and allocation profiles and the GC settings (GOGC), not a micro optimisation.

Checklist

• Width is share of samples. Height is depth. Position and colour mean nothing.
• Find wide boxes in your code, then descend to the plateau where self time sits.
• Expect much of a Go CPU profile to be runtime: allocator, GC and idle threads.
• Use -focus and -ignore to see your code's share and drop idle frames.
• Diff two profiles after a change, and confirm with a benchmark.

The format and tools are documented in the Go diagnostics guide and the pprof tool documentation.