← ~/blog

Clocks Lie: What NTP Drift Did to Our Idempotency Keys

 /  systems  /  303 words

We had a dedupe bug that only showed up on one worker box, only under load, and only sometimes. Those are the ones that age you.

The setup: incoming webhook events carried a timestamp and an ID. To dedupe, we kept a rolling window of recently seen IDs, and the window was time based. If an event's timestamp was older than 150ms past what we had already processed, we treated the ID cache as authoritative and moved on. Cheap and mostly correct.

Then worker-07 started letting duplicates through. Same code as every other box. The logs showed events being judged as outside the window when their siblings on other machines judged them inside it. Eventually I did the thing I should have done first:

chronyc tracking output on worker-07 reporting the system clock 0.184722319 seconds slow of NTP time, with a last offset of -0.181203401 seconds.

The box was 184 milliseconds slow. Our whole windowing scheme assumed all workers shared roughly the same "now" and this one was living slightly in the past. Its VM had been migrated between hosts a week earlier and chrony was still slewing the clock back gently, which is what chrony does, because stepping a clock backwards breaks other things.

The real lesson isn't "monitor NTP" although yes, alert on offset, we do now. The lesson is that any distributed logic that compares timestamps from different machines is comparing readings from different instruments and treating them as one. Wall clocks across a fleet agree to within a few milliseconds on a good day and disagree by hundreds on a bad one.

What we changed: dedupe now keys purely on event ID against a shared Redis set with a TTL. No cross machine time comparison anywhere in the path. Where ordering matters we use sequence numbers from the source system, which is the source's clock, singular, instead of our clocks, plural. One clock can be wrong. It cannot disagree with itself.