Ramblings of an aging IT geek
← Ramblings of an aging IT geek
performance

flamegraphs and a hot path i never suspected

A profiling session that found the real cost wasn't the algorithm I'd been staring at, but a logging call nobody thought to look at.

A flamegraph-style server performance chart

I spent two days being clever about an algorithm that turned out to be innocent. The service was slower than it should be, I had a theory about where, and I rewrote that part twice before admitting I was guessing. So I did what I should have done first and ran perf against it.

The flamegraph was humbling. The function I'd been optimising was a thin sliver, barely visible. The fat tower in the middle, eating something like a third of the samples, was a structured logging call on the request path. It was serialising a context object to JSON on every single request, at a log level we filtered out before anything was written. We were paying the full cost of formatting a line that went straight to /dev/null.

The fix took four lines: guard the expensive field construction behind a level check so it never runs unless the log would actually be emitted. Throughput came back, the flamegraph flattened, and the algorithm I'd agonised over never needed touching at all.

The lesson is the one everybody knows and nobody applies under pressure. Profile before you optimise. Your intuition about where the time goes is a hypothesis, not data, and mine was confidently wrong for two days. The flamegraph doesn't care what you suspect. It just shows you where the CPU actually went, which is the only opinion that counts.