The bug report said an event was processed before it was created. The timestamps agreed: the downstream record was forty milliseconds older than the upstream one that caused it. Nothing was corrupted and no code was wrong — two machines simply disagreed about the time, and a system that used wall clocks to order events across them inherited that disagreement as data.
Clock skew of tens of milliseconds between healthy servers is normal. Skew of seconds happens when synchronisation fails, and it will fail sometimes. Any logic whose correctness depends on comparing timestamps from different machines is therefore built on an assumption the infrastructure never promised.
Three things called time
Physical time answers 'when did this happen in the world', and is what humans, contracts and regulators care about. Logical time answers 'what caused what', which is what most distributed algorithms actually need. Hybrid time tries to give you both at once. Conflating the first two is the root of nearly every ordering bug I have debugged.
A Lamport clock is the minimal logical mechanism: a counter per node, incremented on every event, carried on every message, and raised to the maximum of local and received values on receipt. It guarantees that if A caused B, then A's counter is lower than B's. It says nothing about events that did not influence each other, and that is not a defect — it is the honest answer, because there is no meaningful ordering between them.
class HybridClock:
"""Hybrid logical clock: physical time you can read, causality you can trust."""
def __init__(self):
self.wall = 0 # milliseconds, close to real time
self.logical = 0 # tiebreaker within the same millisecond
def now(self) -> tuple[int, int]:
physical = int(time.time() * 1000)
if physical > self.wall:
self.wall, self.logical = physical, 0
else:
self.logical += 1 # clock did not advance; keep monotonic
return (self.wall, self.logical)
def observe(self, remote: tuple[int, int]) -> tuple[int, int]:
physical = int(time.time() * 1000)
rw, rl = remote
# Never go backwards, and always stay ahead of anything we have seen.
merged = max(self.wall, rw, physical)
# Never go backwards, and always stay ahead of anything we have seen.
if merged == self.wall == rw: logical = max(self.logical, rl) + 1
elif merged == self.wall: logical = self.logical + 1
elif merged == rw: logical = rl + 1
else: logical = 0
self.wall, self.logical = merged, logical
return (self.wall, self.logical)The value of the hybrid form is that the timestamp is still approximately wall time — you can read it in a log, sort by it, and it means roughly what it appears to mean — while the logical component guarantees that causally related events always compare correctly, even when the physical clocks disagree.
Rules that avoid the whole category
- Never use wall-clock comparison across machines to decide ordering, deduplication or last-write-wins. That is the bug.
- Use a monotonic clock for durations. Wall clocks jump backwards during synchronisation, and a negative elapsed time will find your worst code path.
- Record both the event time and the processing time. Collapsing them makes late-arriving data indistinguishable from reordering.
- Monitor clock offset per node as an infrastructure metric, and alert on it. Skew is usually visible for hours before it causes a visible bug.
- Where correctness genuinely requires it, use a system that gives bounded uncertainty and waits it out, rather than pretending the bound is zero.
Two servers do not agree on what time it is. Every design that assumes otherwise is one clock resynchronisation away from being interesting.
The debugging benefit alone justifies the change. Tracing a request through six services using wall-clock timestamps means reading spans that overlap impossibly and arguing about which log is wrong. Causally ordered timestamps mean the sequence you read is the sequence that happened, which is a surprisingly large improvement in how long an incident takes to understand.