Python Testing & Debugging Beyond unittestAdvanced Python testing playbooks
Debugging & Performance

Reading Flame Graphs from py-spy Output

A flame graph looks like a landscape and is often read like one: people point at the tallest peak. The tall parts are just deep call stacks. The information is in the width of each frame — the share of samples in which that function was executing — and reading it correctly turns a picture into a specific, testable conclusion about where a process spends its time.

Prerequisites

Solution

Capture a window that covers several iterations of whatever the process does, then read the graph from the bottom up:

Bash
$ py-spy record --pid 4242 --duration 60 --rate 100 --output profile.svg
$ py-spy record --pid 4242 --duration 60 --format speedscope --output profile.json

The reading procedure is mechanical.

Start at the bottom. The base frame is the entry point and spans everything. Each level up is a callee, and the width of a frame is the fraction of samples in which it appeared on the stack.

Follow the widest child at each level. That path is where the time is. A frame that is 70% wide at depth three and splits into two 35% children at depth four tells you the cost is evenly divided; one that stays 70% wide for five levels tells you a single call chain owns the time.

Stop where the width stops narrowing. The frame at the top of that path — the widest leaf — is where the process is actually executing. That is the function to optimise, and it is often nowhere near the tallest tower on the graph.

Ignore height. A tower fifteen frames tall and two pixels wide is a deep call chain that almost never runs. It looks dramatic and costs nothing.

Four shapes and what each means A table of four flame graph shapes - a wide flat plateau, a tall narrow tower, a wide frame splitting into many narrow ones, and a uniformly noisy graph - with the interpretation and next action for each. Four shapes and what each means Criterion Means Next step wide flat plateau one leaf owns the time optimise or avoid that call tall narrow tower deep but rare path ignore it wide frame, many children dispatch overhead reduce call volume uniform noise no hot spot, or wrong window record longer, check idle
Only the first and third rows point at work worth doing; the second is a distraction and the fourth means the capture needs redoing.

Why this works

py-spy samples the interpreter's stack at a fixed rate — 100 Hz by default — and each sample is a complete stack trace. The flame graph aggregates identical stacks and draws each frame with a width proportional to the number of samples containing it. Because sampling is time-based rather than event-based, width measures time on the stack rather than call count, and the two can differ enormously: a function called once and taking a second looks identical to one called a million times taking a microsecond each. That is the property that makes flame graphs good at finding where time goes and useless for finding what is called too often — a question cProfile's ncalls column answers directly, as covered in interpreting cProfile: cumulative vs total time.

The reading procedure, in order A left-to-right procedure: start at the base frame, follow the widest child at each level, stop at the widest leaf, and confirm the finding against a second capture. The reading procedure, in order base frame the entry point widest child follow the time widest leaf where work happens confirm a second capture
Following width rather than height is the whole technique; the confirmation step is what stops a one-off spike becoming a refactor.

Wall-clock, CPU and idle threads

The most common misreading is treating a flame graph as a CPU profile. By default py-spy samples every thread that is running Python, and a thread blocked in socket.recv is still on a stack — so it appears in the graph, wide, and looks like a bottleneck.

Two flags disambiguate. --idle explicitly includes threads that are sleeping or waiting, which makes blocking visible rather than hidden; without it py-spy skips idle threads, and a mostly-waiting process produces a sparse graph. And in the terminal view, py-spy top shows an OwnTime column alongside TotalTime, which is the closest thing to a CPU measure the sampler provides.

Bash
$ py-spy top --pid 4242
Total Samples 5900
GIL: 38.00%, Active: 41.00%, Threads: 9

  %Own   %Total  OwnTime  TotalTime  Function (filename)
 31.00%  31.00%   18.2s     18.2s    read (ssl.py)
  6.00%  44.00%    3.5s      25.9s    handle_request (server.py)

The GIL: figure at the top is the single most useful number for a threaded service. A process with 38% GIL and nine threads is not CPU-bound in Python — it is waiting, and adding workers will help. One at 95% GIL is serialised on the interpreter lock, and the fix is either less Python work per request or a different concurrency model entirely.

Comparing two captures

"Faster after the change" needs two comparable measurements, and comparability is easy to lose.

Use the same duration, the same workload and the same sample rate. Percentages are relative to the capture, so a 60-second capture under light load and a 60-second capture under heavy load report different percentages for identical code. Where possible, drive both captures with the same load generator and the same request count rather than the same wall time.

Speedscope's left-heavy view is the most useful comparison mode: it sorts frames by total time rather than by call order, so the same function appears in the same place in both captures and the widths can be compared directly. For an automated comparison, --format raw emits collapsed stacks that a differential flame graph tool can subtract:

Bash
$ py-spy record --pid 4242 --duration 60 --format raw --output before.txt
# ... deploy the change ...
$ py-spy record --pid 4242 --duration 60 --format raw --output after.txt
$ difffolded.pl before.txt after.txt | flamegraph.pl > diff.svg

A differential graph colours frames that grew and shrank, which turns "is it faster" into a per-function answer — and frequently reveals that the optimised function did improve while a second one got slower under the new call pattern.

Edge cases and failure modes

  • Native frames are missing without --native, so a C extension appears as a single wide leaf with nothing below it.
  • Very short captures over-represent whatever ran. Ten seconds of a process that does a slow thing once a minute is noise; capture across at least two cycles.
  • Subprocesses are separate. py-spy samples one process unless --subprocesses is passed, and a worker pool's real work is in the children.
  • Thread names are more useful than thread ids. Naming threads at creation makes a multi-threaded graph readable; unnamed threads all look alike.
  • A sampled profile cannot prove absence. A function with no samples was probably not hot, but "probably" is the strongest available claim.
  • The graph is wall-clock, not allocation. Memory growth needs tracemalloc, and a slow function that allocates heavily may be slow because of the allocator rather than its own logic.

Turning a reading into a change

A flame graph is only useful if it ends in a decision, and there are four decisions it can support — each with a different follow-up measurement.

Optimise the leaf. The widest leaf is doing real work and the work is necessary; make it faster. Confirm with a before-and-after capture under identical load, and expect the graph's shape to change rather than merely shrink.

Remove the calls. The leaf is cheap per call but called constantly. The flame graph cannot show that — width is time, not count — so the follow-up is cProfile on the same workload to read ncalls, as described in interpreting cProfile.

Move the work off the hot path. The frame is legitimate but does not need to happen inline — a cache warm-up, a metric flush, a serialization that could be lazy. The follow-up measurement is latency at the percentile that matters, not total CPU.

Do nothing. The widest frame is a socket read and the service is I/O-bound. This is the most common outcome of a first profile, and recognising it early saves a week of optimising code that is not the bottleneck. The follow-up is a GIL: reading and a concurrency change rather than a code change.

Whichever decision follows, record the capture alongside it. A flame graph attached to the pull request that changed the code is the only durable evidence that the change was justified, and it is what makes the next person's investigation start from a measurement rather than from a guess.

Frequently Asked Questions

What does the width of a flame graph frame mean? The fraction of collected samples in which that frame was on the stack. It is proportional to wall-clock time spent there, not to the number of calls, so a wide frame may be one slow call or a million fast ones.

Why is my flame graph one flat plateau? Because one function dominates the samples and calls nothing below it — typically a C extension, a socket read, or a lock acquisition. Add --native to see below the Python boundary.

How do I compare before and after? Capture both with the same duration and workload, then use speedscope's left-heavy view or a differential flame graph. Comparing raw percentages between runs of different lengths is misleading.

A checklist before acting on a flame graph A stack of four checks to run before acting on a flame graph: confirm the capture window was representative, confirm idle threads were included or excluded deliberately, check the GIL percentage, and confirm the widest leaf is not a blocking call. A checklist before acting on a flame graph representative window several cycles of the real workload idle threads --idle included or excluded on purpose the GIL percentage distinguishes CPU-bound from waiting the widest leaf is it work, or is it a socket read?
Three of the four checks separate "slow" from "waiting", which is the distinction a flame graph makes easiest to get wrong.

← Back to CPU Profiling with cProfile and py-spy