Flame graphs and CPU profiling

A profiler answers one question: where does the time go? A sampling profiler pauses the program at a fixed rate, records the current call stack, and repeats. A function that appears in 30% of samples is using about 30% of the CPU. That is enough to find the expensive part of a service without guessing.

The big idea

There are two families of profiler.

• Instrumentation profilers add timing code at every function call. They count calls exactly, but the overhead can be 2 times or more. That overhead makes tiny, frequently called functions look far more expensive than they are. Python's cProfile is the familiar example.
• Sampling profilers interrupt the program at a fixed rate and record the stack. Overhead is usually a few percent, so you can run them in production.

Walking through a flame graph

A flame graph turns thousands of stacks into one picture. Each box is a function. Read it like this.

• The y-axis is stack depth. The bottom box is the root, such as main. Each box sits on top of the function that called it.
• The x-axis is not time. Boxes are sorted alphabetically so identical stacks merge. A box's width is the share of samples that included that function.
• Wide boxes are where time goes. A wide box with nothing on top of it is a plateau. The CPU spent its time in that function's own code.

Follow the widest path upward. get_orders handler is 94% wide, but most of that width sits in its children. The widest child is serialize_response at 68%. Inside it, dataclasses.asdict takes 41%, and almost all of that is copy.deepcopy at 38%. That box has nothing on top of it, so it is the plateau to attack.

Notice what is missing: database time shows as only 19% here. A CPU profile records time spent running on the CPU. It does not record time spent waiting for the database to answer. That gap is covered in off-CPU time.

Taking a profile

Each runtime has a tool. Here are the common ones.

perf runs at 99 Hz rather than 100 Hz so its samples do not line up with periodic work in the program.

For many hosts at once, continuous profilers such as Pyroscope, Parca and Google Cloud Profiler sample all the time at a low rate.

Allocation profiles: the memory side

Memory has two profiles, and they answer different questions.

• Retained memory is what is alive right now. Take two heap snapshots a few minutes apart and diff them. Whatever keeps growing is the leak.
• Allocation rate is how many bytes are allocated each second, even if they die at once. A high rate means the garbage collector runs often. In a service that allocates 2 GB per second, the collector can take CPU that your code needs. See memory management for how collectors work.

Common fixes: reuse buffers, preallocate slices and maps to their final size, stream large responses, and avoid accidental deep copies like the asdict above.

Common mistakes

• Reading the x-axis as time. It is only the share of samples.
• Reading a CPU graph for a slow request that is mostly waiting. The graph will look healthy.
• Profiling a laptop with tiny data. Profile a realistic load on production-like hardware.
• Trusting old JVM profilers that sample only at safepoints. Safepoint bias can move time onto the wrong method. async-profiler avoids this.

Check yourself

1. A function takes 30% of samples. About how much CPU is it using? Roughly 30% of the CPU, since samples are taken at a fixed rate.
2. A flame graph shows a wide box with nothing on top. What does that mean? The CPU spent its time in that function's own code. It is a plateau to optimize.

Key takeaways

• Sampling profilers are cheap enough for production and show where CPU time goes.
• In a flame graph, width is the share of samples and height is stack depth. The x-axis is not time.
• A wide plateau is the place to look first.
• Allocation rate drives garbage collector cost, so profile it too.

Further learning

Brendan Gregg invented flame graphs in 2011. His page covers how to read them and the variants for CPU, off-CPU and memory.

Brendan Gregg: Flame GraphsHomepage for Flame Graphs: a visualization for stack traces.brendangregg.com py-spy: sampling profiler for PythonSampling profiler for Python programs. Contribute to benfred/py-spy development by creating an account on GitHub.GitHub

Next, read off-CPU time to find the time that a CPU profile cannot see.