After a routine platform bump in July, the order service needed about forty percent more CPU for the same work. Requests per second unchanged, p95 up by sixty milliseconds, node count up by four. Nothing was broken and nothing alerted. It took us three weeks to find out why, and the tooling we were so pleased with contributed almost nothing.
We had metrics, logs and traces, and they agreed the service had become more expensive. Traces go down to repository methods and HTTP clients, and the extra time was in none of those spans. It was spread thinly across every request, in the gaps, which is the signature of something happening inside the process rather than at one of its boundaries: serialisation, garbage collection, a lock, a pattern being compiled. The bump had moved thirty four dependencies at once.
So we bisected. Candidate builds onto a canary, one dependency reverted at a time, comparing CPU seconds per request over an hour of real traffic each because the difference only shows at production concurrency. Five days of that, plus a fortnight of it not being anybody's only job.
What settled it in under two hours was a continuous profiler, which we installed only because we had run out of other ideas. Thirty one percent of on CPU time was in a regular expression being compiled, inside a validation library whose new version had stopped caching compiled patterns unless you hand it a flag. Our fix was one line in a configuration class.
CPU and heap profiles are now collected continuously from every pod, at a cost we measured at just under two percent, kept for thirty days and labelled by release, so two builds can be compared as a difference rather than as an argument. A heap dump is written to object storage on out of memory, since the container that could have explained it is otherwise deleted within seconds. And a per release panel carries CPU seconds and bytes allocated per request, which now fails a release on a regression over ten percent. It has caught two more since, one of them ours.
Our monitoring could tell us that a service had become more expensive. Nothing we owned could tell us which code was spending the money, and that is a different instrument, not a better dashboard.
– Sergey Shinder
