Profiling and benchmarking

Sampling vs instrumentation profilers

Two ways to find where a program spends time. A sampling profiler interrupts the program many times a second and records the current call stack. Nobody edits your code; the profiler just keeps asking "what are you doing right now?" and tallies the answers. Go's CPU profiler samples about 100 times a second. An instrumentation profiler does the opposite: it wraps functions with enter/exit hooks that count every call and time it exactly.

Sampling is statistical. It misses nothing that runs often, and it costs little, so it is what you reach for on a live service or a hot path. Instrumentation is exact per call but expensive: the hooks add overhead to every call, and on tiny or inlined functions that overhead can dwarf the real work and even stop the compiler from inlining, which changes the thing you were trying to measure. A function called ten million times pays the hook cost ten million times.

Rule of thumb for this level: sampling to find where the time goes, instrumentation (or a targeted timer) only when you already know the function and need an exact count.

CPU, allocation, and heap profiles answer different questions

A CPU profile tells you where on-CPU time went. It will not explain a request that is slow because it waits on a database or a lock, because a thread parked on I/O is burning no CPU and shows up in no CPU sample. For waiting, you want an off-CPU or wall-clock profile.

Memory splits into two questions that people confuse:

• Allocation profile: how much your code allocated in total over the run, including everything the garbage collector already freed. This is what you read when GC is the problem, because churn (allocating and freeing constantly) is what makes the collector work.
• Heap (in-use) profile: what is live right now. This is what you read for a leak or steady growth.

In Go the same data drives both: go tool pprof defaults to in-use space for the heap profile and total allocated bytes for the allocs profile. Ask "am I allocating too much?" (allocs) or "what is still holding memory?" (in-use), and pick accordingly.

How to read a flame graph

A flame graph is the standard way to view a sampled CPU profile. Three things to internalize, because each has a matching wrong reading:

• Width is the fraction of samples a frame appeared in, which approximates its share of on-CPU time. Wide means expensive.
• Height (the y-axis) is stack depth: who called whom. A tall tower is just a deep call chain, not a slow one.
• The x-axis is not time. Frames are sorted alphabetically so identical stacks merge into one wide block. Left and right mean nothing about order.

Wrong "that frame is on the left and it's wide, so it ran first and that one call was slow." The x-axis is not a timeline, and a wide frame is many samples summed, not one long call. Right scan the top edge. The widest leaf frames are where the CPU actually sat, and their ancestors below show how execution got there. Start wide, ignore the tall-and-thin.

Microbenchmarks: the number is lying until proven otherwise

The classic beginner benchmark measures nothing:

func BenchmarkParse(b *testing.B) {
    input := loadSample()
    for i := 0; i < b.N; i++ {
        parse(input)   // result thrown away
    }
}

The return value of parse is never used, so the compiler is free to delete the call entirely (dead-code elimination). You end up timing an empty loop and reporting an impossibly small number like 0.3 ns/op.

The fix is to make the result escape so the compiler cannot drop it. Return it, accumulate it into a package-level variable, or use the loop form that keeps results alive:

func BenchmarkParse(b *testing.B) {
    input := loadSample()
    for b.Loop() {          // Go 1.24+: keeps loop-body results alive
        parse(input)
    }
}

b.Loop() also resets the timer on the first call and stops it at the end, so setup and cleanup do not count. Two more habits at this level. Run -benchmem (or call b.ReportAllocs()) so you see allocations per op, not just time; a rewrite that is a hair faster but allocates twice as much is usually a loss once GC is in the picture. And let the framework pick the iteration count: it reruns with a larger b.N until the timing is stable, so a single fast run is not the reading.

One thing a microbenchmark cannot tell you: whether the function matters. A 40x speedup on a function that is 1% of a request buys you nothing. Profile first to find what is actually wide, then benchmark that.

Where sampling profilers lie: safepoint bias and resolution

A sampling profiler is only as honest as the moments it is allowed to sample. On the JVM, many profilers can walk a thread's stack only when the thread is at a safepoint, a spot where the JVM knows the stack is in a consistent state. The compiler inserts safepoint polls at specific places (loop back-edges, method returns), not uniformly, and a thread has to reach one before it can be sampled. So the profiler ends up sampling a skewed set of program points, and time gets attributed to whatever method happens to sit near a safepoint rather than to the code that actually burned the cycles. This is safepoint bias, and it can point you at the wrong line with total confidence.

async-profiler exists largely to dodge this. It samples via AsyncGetCallTrace and Linux perf_events, so it can capture a stack at an arbitrary instruction, outside safepoints, and it sees native and kernel frames plus non-Java threads (GC, JIT compilers) that a pure-Java profiler cannot.

Resolution is the other limit, and it holds for every sampler, not just the JVM. At roughly 100 Hz (Go's default) a function that runs for under a few milliseconds may catch zero samples and simply not appear. Raising the rate finds shorter functions but adds overhead, and there is a floor: a function that never lands in a single sample is invisible, no amount of staring at the profile will surface it. Beware frequency aliasing too, where a periodic workload lines up with the sample interval and gets systematically over- or under-counted.

In-use vs allocated, and how allocation profiling samples

The heap/allocs split is worth stating precisely because the two answer opposite questions. Go's heap profile reports statistics as of the most recently completed GC and, by default, shows in-use space (live objects) and elides recent allocations so garbage does not skew it toward noise. The allocs profile is the same underlying data displayed as total bytes allocated since the program began, garbage included. Leak or steady growth: read in-use. GC pressure from churn: read alloc-space.

Allocation profiling is itself sampled, so it is cheap enough to leave on. In Go (runtime 1.x) the memory profiler records roughly one sample per 512 KB allocated, tunable with MemProfileRate. async-profiler samples allocations off TLAB (thread-local allocation buffer) events, so it catches the allocation slow path without instrumenting every new. In both cases you are reading a scaled estimate, not an exact count, which is fine for finding the fat allocation sites and misleading if you treat the absolute bytes as gospel.

Match the profile to the symptom. High p99 with low CPU usually means off-CPU: threads blocked on locks or I/O, which a CPU profile shows as idle. Go exposes block and mutex profiles for exactly this (enabled with SetBlockProfileRate and SetMutexProfileFraction), attributing blocked or contended time to the stack that waited.

Microbenchmarks: what the JIT and the compiler do to your numbers

Dead-code elimination is the first trap (covered in the middle notes: consume the result). Constant folding is its sibling and bites harder on the JVM. If a benchmark computes over a value the compiler can prove is constant, it folds the whole expression to a literal at compile time and your loop measures nothing. JMH's answer is to read inputs from @State objects the JIT cannot treat as constants, and to sink outputs through a return or Blackhole.consume, which forces the result to escape.

Warmup is the JVM-specific one. The first thousands of iterations run interpreted or lightly compiled; the JIT only reaches steady-state native code after the method is hot, and profile-guided decisions (inlining, branch prediction) settle even later. Measure before that and you time the wrong program. JMH runs explicit @Warmup iterations and, crucially, @Forks each benchmark into a fresh JVM so that one benchmark's JIT profile does not pollute the next (run two implementations in one JVM and the first can bias the compilation of the second). Go's harness sidesteps warmup differently: it reruns the body with a growing b.N until timing is stable and there is no JIT to warm.

The pitfall no harness fixes is the gap between the loop and production. A microbenchmark runs with a hot cache, a monomorphic (single-target) call site, a trained branch predictor, and no competing GC or allocator pressure. Real traffic has cold caches, megamorphic dispatch, and a collector running against you. A 40x microbenchmark result is a hypothesis about production, not a measurement of it.

Coordinated omission: your load generator is probably lying

Gil Tene's coordinated omission is a measurement bug in how latency is recorded, and it is squarely a benchmarking-methodology problem. A closed-loop load generator issues the next request only after the previous response returns. When the system stalls for 200 ms, that client cannot send during the stall, so the requests that should have been issued in that window are never even attempted. You record one slow response instead of the whole backlog, and your p99 comes out flattering because the meter stopped exactly when the system was at its worst.

The mental model: if you were supposed to send a request every 1 ms and the system freezes for 200 ms, a correct measurement counts 200 requests whose latency degrades from 200 ms down to 1 ms, not a single 200 ms sample. Two fixes. Drive load open-loop at a fixed schedule with a tool built for it (wrk2 issues at constant throughput regardless of responses), or correct after the fact: HdrHistogram's recordValueWithExpectedInterval(value, expectedIntervalBetweenValueSamples) synthesizes the omitted samples when you tell it the intended interval (or copyCorrectedForCoordinatedOmission after recording). Either way, the tail you were trying to measure reappears. (How you then aggregate those percentiles across shards and windows lives in the backend-performance notes; it does not average.)

Continuous profiling in production

Ad-hoc profiling captures a few minutes when you remember to, which means you rarely have a profile of the incident that mattered. Continuous profiling samples always, at low rates, across the fleet, and keeps the history, so you can open the flame graph for 3 a.m. last Tuesday.

The reason it is affordable is the same reason sampling works at all: you sample sparsely in time and across machines. Google's GWP paper reports profiling overhead "negligible, less than 0.01 percent" by sampling a small fraction of machines at any moment rather than everything continuously. Modern systems (Parca, Pyroscope, and similar) do the same with eBPF or in-process samplers at a few percent or less.

What it unlocks beyond a single flame graph is comparison. A differential flame graph subtracts one profile from another and colors what grew, so a canary deploy becomes a direct before/after read: ship the rewrite to a slice of production, compare its profile against the baseline, and see whether your hot function actually shrank on real traffic. That is the measurement that decides the change. The lab microbenchmark only told you it was plausible.