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

perf top on a box that shouldn't be busy

A quiet web node was burning 30% of a core doing nothing, and perf top pointed straight at the culprit.

A line graph climbing across a rack of servers

The alert was the dull kind. CPU on one of the web nodes sitting at 30% with no traffic to speak of. It was a Friday, the box served maybe two requests a second, and 30% of a core was unaccounted for. Nobody likes a number that doesn't add up.

Top tells you a process is busy. It does not tell you what the process is busy doing, and that gap is where I usually waste an hour guessing. So I skipped the guessing.

perf top -p $(pgrep -n our-service)

perf top is the bit of the toolchain I forget I have until I need it. It samples the running process and shows you, live, which functions are eating the cycles, sorted by overhead. No instrumentation, no restart, no clever flags. You just watch the symbols sort themselves.

A terminal showing sampled function overhead

Top of the list, by a wide margin, was a regex compile inside a logging helper. Not the log write. The compile. Someone had written a "redact secrets from log lines" pass that recompiled the same pattern on every single line emitted, and the box was emitting a lot of debug lines because debug logging had been left on after the last incident. So: no traffic, plenty of CPU, all of it spent rebuilding a regular expression we already knew the shape of.

Two things fixed it. Hoist the compile out of the hot path so it happens once, and turn the debug logging back off, which someone should have done a fortnight ago. CPU dropped to the low single digits and stayed there.

The lesson isn't "regexes are slow", because they aren't, particularly. The lesson is that "busy" is a symptom and perf top is the cheapest way I know to turn a symptom into a function name. If the symbols come back as a wall of hex with no names, install the debug symbols for whatever you're profiling and it gets a great deal more useful. Worth the disk.