How a Dead NTP Daemon Broke a Redis Lock and Ran Payout Reconciliation Twice

09:14 UTC. Finance's automated reconciliation summary posts to #finance-ops: "ledger delta exceeds threshold: $61,412.18 unexplained, previous day." Thirty seconds later it pages the on-call payments engineer. Nothing in the deploy log from the last 48 hours. The last change to the reconciliation job was three weeks old.

the setup

Every night at 02:00 UTC, a fleet of worker hosts runs a cron entry that kicks off payout-reconciliation: a job that scans merchant payouts for discrepancies flagged during the day (chargebacks, delayed settlements, currency conversion drift) and writes a compensating credit or debit to each affected merchant's ledger. It has to run exactly once. Running it twice means issuing the same correction twice.

To guarantee that, every worker tries to acquire a lock in Redis before starting. The lock implementation predates the current team and does something that looked reasonable at the time: it stores an expiry timestamp inside the lock's own value, computed from the acquiring host's local clock, and any worker checking whether the lock is still held compares that stored timestamp against its own local time.time().

import json
import time
import redis

LOCK_KEY = "lock:payout-reconciliation"
LOCK_TTL_SECONDS = 1200  # 20 minutes, job's usual runtime plus margin

def acquire_lock(r: redis.Redis, owner: str) -> bool:
    existing = r.get(LOCK_KEY)
    if existing:
        payload = json.loads(existing)
        if payload["expires_at"] > time.time():
            return False  # still held, by our own clock
        # looks stale, by our own clock — take it
    r.set(LOCK_KEY, json.dumps({
        "owner": owner,
        "expires_at": time.time() + LOCK_TTL_SECONDS,
    }))
    return True

The bug is in that comparison. time.time() is whichever clock the worker happens to be running on. Redis was never asked what time it is. Every worker was trusting itself.

the scramble

First theory: the payment processor had re-sent a batch of webhooks and the reconciliation job had double-processed one of its inputs. It's happened before, with a different job, and the alert's dollar figure had the suspicious look of a round multiple. Pulling the webhook delivery log for the incident window ruled it out fast, no duplicate deliveries, no retries, nothing unusual from the processor's side.

Second theory: the job had crashed mid-run and its own retry logic had re-applied the same corrections. The scheduler's run history showed exactly one triggered invocation for the night in question, no failures, no retries. One trigger. But the job's own structured logs told a different story once someone actually grepped them instead of trusting the scheduler.

2026-08-24 01:59:41 UTC host=worker-a04 reconciliation: lock acquired, ttl=1200s
2026-08-24 02:00:03 UTC host=worker-b12 reconciliation: lock acquired, ttl=1200s
2026-08-24 02:11:52 UTC host=worker-a04 reconciliation: run complete, 1900 orders processed
2026-08-24 02:14:07 UTC host=worker-b12 reconciliation: run complete, 1900 orders processed

Two hosts, twenty-two seconds apart, both logging a successful lock acquisition for a key that's supposed to allow exactly one holder. Both ran the full batch. Both finished cleanly. Neither one errored, which is why nothing had paged overnight.

the hunt

Redis itself had no memory of this by morning. The key had long since expired and been overwritten by the next night's run. What was left was the lock code and the two hosts involved. Worker-a04 acquired legitimately at 01:59:41, computed its own expiry at roughly 02:19:41, and should have held an uncontested lock for the next twenty minutes. Worker-b12 should have seen an unexpired key and backed off. It didn't.

The only way acquire_lock lets a second host in in that window is if its comparison, payload["expires_at"] > time.time(), evaluates false using b12's clock even though a04's expiry was correct by twenty minutes. That only happens if b12's clock was running fast enough to read a time already past 02:19:41 while it was still actually 02:00 UTC everywhere else. Checking b12's clock against Redis's own confirmed it.

$ ssh worker-b12 -- date -u
Mon Aug 24 02:22:14 UTC 2026

$ redis-cli -h lock-store.internal TIME | head -1
"1756000914"

$ date -u -d @1756000914
Mon Aug 24 02:00:14 UTC 2026

Worker-b12 was twenty-two minutes ahead of real time. At real 02:00:03, when it tried to acquire the lock, its local clock already read past a04's expiry, so its own staleness check said the lock was dead and safe to steal. It deleted the key, wrote its own, and started the same batch a04 was still twelve minutes into.

Why was b12's clock wrong? It runs chrony for time sync, same as every other worker. An AMI patch rolled out eleven days earlier included a cleanup script meant to strip a legacy ntpd unit left over from an older provisioning image.

for unit in $(systemctl list-unit-files | grep -iE 'ntp' | awk '{print $1}'); do
  systemctl disable --now "$unit"
  systemctl mask "$unit"
done

On this AMI, ntpd.service wasn't dead weight, it was an alias unit pointing at the same underlying unit file as chronyd.service, kept for backward compatibility with old provisioning scripts that still referenced it by the old name. Masking ntpd.service masked chrony's own unit underneath it. An existing safety-net cron job that restarts chrony if it isn't running checked systemctl is-active chronyd and, finding it inactive, ran systemctl start chronyd, which fails silently against a masked unit and returns a non-zero exit code the safety script never checked.

$ ssh worker-b12 -- systemctl status chronyd
● chronyd.service
   Loaded: masked (Reason: Unit chronyd.service is masked.)
   Active: inactive (dead)

Without chrony correcting it, a virtualized clock on this hypervisor drifts at roughly two minutes a day under load. Eleven days of unnoticed drift landed almost exactly on twenty-two minutes, comfortably past the twenty-minute margin built into the lock's TTL.

the find

Root cause: the lock's staleness check depended on comparing timestamps generated by two different clocks that were never guaranteed to agree, worker-a04's clock at acquisition time and worker-b12's clock at check time. A patch script's overly broad unit match silently disabled time sync on one host, and the drift that produced was invisible until it exceeded the exact margin baked into this one lock's TTL.

The reconciliation job itself wasn't idempotent against a concurrent second run, either. Both invocations queried for the same set of flagged discrepancies at their respective start times, found the same 1,900 orders, and independently wrote compensating ledger entries for each one. 340 of those orders got processed by both runs before either one finished. Those 340 merchants ended up with a duplicate correction stacked on top of the correct one.

the fix

The lock was rewritten to stop trusting any host's local clock at all. Redis's atomic SET ... NX PX handles acquisition and expiry entirely inside Redis, and release only happens through a Lua script that checks the caller's token before deleting, so a host can never release, or judge the staleness of, a lock it doesn't own.

import uuid
import redis

LOCK_KEY = "lock:payout-reconciliation"
LOCK_TTL_MS = 1_200_000  # 20 minutes, expiry lives entirely on the Redis server

RELEASE_SCRIPT = """
if redis.call("get", KEYS[1]) == ARGV[1] then
    return redis.call("del", KEYS[1])
else
    return 0
end
"""

def acquire_lock(r: redis.Redis) -> str | None:
    token = str(uuid.uuid4())
    acquired = r.set(LOCK_KEY, token, nx=True, px=LOCK_TTL_MS)
    return token if acquired else None

def release_lock(r: redis.Redis, token: str) -> None:
    r.eval(RELEASE_SCRIPT, 1, LOCK_KEY, token)

No worker ever computes or compares a wall-clock timestamp again. If two hosts' clocks disagree by an hour, it no longer matters. Redis's own expiry is the only clock in this system now.

A correct lock still isn't the whole answer, since the two duplicate runs had already proven the job itself needed a second line of defense. Each ledger write now goes through a conditional update that only succeeds the first time a given order is reconciled.

UPDATE payout_ledger
SET compensating_credit_cents = compensating_credit_cents + %(delta)s,
    reconciled_at = now()
WHERE order_id = %(order_id)s
  AND reconciled_at IS NULL
RETURNING id;

If that query returns no row, the job treats it as already handled, by itself or by a concurrent run, and skips it instead of issuing a second credit. This is the guarantee that actually matters. The lock reduces contention; the conditional write is what makes a lock failure survivable instead of expensive.

Separately, every worker's clock offset is now shipped to our metrics pipeline every five minutes, reading directly from chronyc tracking.

offset_ms=$(chronyc tracking | awk -F: '/System time/ {print $2}' | awk '{print $1 * 1000}')
echo "clock.offset_ms:${offset_ms#-}|g" | nc -u -w1 localhost 8125

An alert fires if any host's offset stays above two seconds for three consecutive checks, a threshold with room to spare below the margin any lock in the system depends on. It would have caught worker-b12 within fifteen minutes of chrony going masked, ten days and change before the drift became large enough to matter.

the aftermath

The $61,412 in duplicate credits took four business days to claw back through merchant support, slower and more delicate than the original bug, since some of it had already been paid out to merchant bank accounts by the time finance caught the delta.

Worker-b12's clock has been correct since the incident. The reconciliation job hasn't needed its conditional-write safety net since, but it's stayed in the code, since the lock it's backing up is only as good as the last clock nobody's checked yet.