We spent two hours of a payment incident arguing about a duplicate request that never existed. The timeline we had assembled from the logs showed the gateway's response leaving four hundred milliseconds before our service sent the request it was responding to. The only story that fits that is a retry we had forgotten about, so we went looking for one, and there was no such thing to find.
One host's clock was eleven seconds ahead of the others.
Our log pipeline sorts on the timestamp the emitting process writes into the line, which is the obvious thing to do and which we had all quietly assumed was a fact about the world rather than a claim made by a machine about itself. A base image rebuild in the summer had dropped the time synchronisation daemon from one of our image variants. The seven hosts built from it had been free running ever since, drifting a couple of seconds a week, in different directions depending on the hardware. Nothing else in the estate noticed, because nothing else in the estate compared two clocks.
It was not only the timeline. An alert that counts errors in a five minute window was placing that host's records in the wrong bucket, so a genuine spike had been smeared across two windows and never crossed the threshold. And a certificate validity check on one of those hosts had started failing a week earlier with an error nobody could reproduce anywhere else, which we had written off as flaky.
Clock offset is now a metric we collect, with a warning at half a second and a page at five. It sits on the platform dashboard next to disk and memory, because it is exactly that kind of number. The log pipeline stamps every line with an ingest time as well as the emitted time, and the incident view can switch between them, which makes a skewed host visible immediately as a line whose two timestamps disagree. The daemon went into the base image with a test that asserts it is running.
The wider habit is that we no longer reconstruct causality across hosts from timestamps at all when it matters. Ordering within one process is real. Ordering between two machines is a comparison of two independent opinions, and an incident is precisely when you are least able to check whether they agree.
– Sergey Shinder
Top comments (0)