Postmortem: The Runner That Wrote Every Row Twice

At 02:14 the nightly enrichment job reported success, and the warehouse reported 312 rows where 200 belonged. Nobody had shipped a feature that night; the runner had been reclaimed and restarted, and the job had no way to tell the difference between resume and start over. The timeline below is a synthetic reproduction you can rebuild with the three scripts in this post, so treat it as a pattern to test your own pipeline against rather than a claim about any particular system.

The timeline, as the logs told it

The job started normally at 02:00 and worked through its queue one item at a time, committing each result as it went. Around 02:11 the host reclaimed the instance without warning, which is ordinary behaviour for short-lived compute and not a failure you can retry your way out of. The supervisor noticed the dead process a minute later, restarted the worker, and the worker began again at item zero with the same confidence as the first time.

02:00:03  worker  start   run_id=(none)  items=200
02:11:47  worker  item    task-118
02:11:47  runner  notice  instance reclaimed by host
02:12:05  worker  start   run_id=(none)  items=200
02:19:31  worker  done    rows_written=312  status=ok

From the supervisor's point of view everything looked healthy, because the process existed, the queue was draining, and the final status said ok. The only signal that something had gone wrong lived in the data itself, and nobody was watching the row count. Forty-seven minutes later a dashboard query turned into a short argument about whether 312 was in fact the expected total.

What actually contributed

Three factors combined, and not one of them would have caused the incident alone. The first was treating the runner's local disk as the system of record, which quietly assumed that the machine would outlive the work it was doing. The second was a retry path that was safe in the HTTP sense but not in the data sense, because a restart is just a retry wearing different clothes.

The third factor is the one people skip in review: the health check measured liveness rather than progress, so a worker looping happily through already-done items looked identical to a worker moving forward. Add a success status written by the worker itself, rather than derived from the rows it produced, and the incident becomes invisible until someone counts. None of these are exotic bugs; they are default assumptions that hold right up until the instance disappears.

Reproducing it in about five minutes

You need nothing but Python 3 and its bundled sqlite3, which keeps the reproduction small enough to run on any laptop.

# worker.py — the version that wrote every row twice
import sqlite3, time

con = sqlite3.connect("warehouse.db")
for i in range(200):
    con.execute("INSERT INTO records(task_id, payload) VALUES (?, ?)",
                (f"task-{i:03d}", "payload"))
    con.commit()
    time.sleep(0.01)

# incident_repro.py — kills the worker mid-run, restarts it, then counts duplicates
import os, random, signal, sqlite3, subprocess, sys, time

HERE = os.path.dirname(os.path.abspath(__file__))
DB = os.path.join(HERE, "warehouse.db")
WORKER = os.path.join(HERE, os.environ.get("WORKER", "worker.py"))

def reset():
    if os.path.exists(DB):
        os.remove(DB)
    con = sqlite3.connect(DB)
    con.execute("CREATE TABLE records(task_id TEXT, payload TEXT, idem_key TEXT)")
    con.commit()
    con.close()

def report():
    con = sqlite3.connect(DB)
    total = con.execute("SELECT COUNT(*) FROM records").fetchone()[0]
    dupes = con.execute(
        "SELECT COUNT(*) FROM (SELECT task_id FROM records "
        "GROUP BY task_id HAVING COUNT(*) > 1)").fetchone()[0]
    con.close()
    print(f"rows={total} duplicated_task_ids={dupes}")

reset()
attempt = 0
while True:
    proc = subprocess.Popen([sys.executable, WORKER], cwd=HERE)
    deadline = time.time() + random.uniform(0.2, 0.9)
    while time.time() < deadline and proc.poll() is None:
        time.sleep(0.02)
    if proc.poll() is None:
        attempt += 1
        os.kill(proc.pid, signal.SIGKILL)
        proc.wait()
        print(f"attempt {attempt}: SIGKILL mid-run")
    else:
        break
report()

Run it, and the last line will show duplicated task ids above zero, because the second process had no memory of the first. That is your incident, compressed from forty-seven minutes into roughly two seconds.

The fix: one transaction, one key, one heartbeat

The durable fix is not a bigger retry budget; it is making the unit of work atomic with the record that says the work happened. Commit the row and its checkpoint together, give the row a deterministic idempotency key, and a kill between the two becomes impossible rather than unlikely.

# guarded_worker.py — same job, safe to restart at any point
import hashlib, os, sqlite3, time

HEARTBEAT = os.environ.get("HEARTBEAT_FILE", "heartbeat.txt")
con = sqlite3.connect("warehouse.db", isolation_level=None)
con.execute("PRAGMA journal_mode=WAL")
con.execute("""CREATE TABLE IF NOT EXISTS records(
    task_id TEXT PRIMARY KEY, payload TEXT NOT NULL, idem_key TEXT NOT NULL UNIQUE)""")
con.execute("""CREATE TABLE IF NOT EXISTS checkpoints(
    task_id TEXT PRIMARY KEY, completed_at REAL NOT NULL)""")

def idem_key(task_id, payload):
    return hashlib.sha256(f"{task_id}:{payload}".encode()).hexdigest()

for i in range(200):
    task_id, payload = f"task-{i:03d}", "payload"
    if con.execute("SELECT 1 FROM checkpoints WHERE task_id = ?", (task_id,)).fetchone():
        continue
    con.execute("BEGIN IMMEDIATE")
    try:
        con.execute("INSERT INTO records(task_id, payload, idem_key) VALUES (?, ?, ?) "
                    "ON CONFLICT DO NOTHING", (task_id, payload, idem_key(task_id, payload)))
        con.execute("INSERT OR REPLACE INTO checkpoints(task_id, completed_at) VALUES (?, ?)",
                    (task_id, time.time()))
        con.execute("COMMIT")
    except Exception:
        con.execute("ROLLBACK")
        raise
    with open(HEARTBEAT, "w") as fh:
        fh.write(f"{task_id} {time.time():.3f}\n")
    time.sleep(0.01)

Swap the worker and rerun the same harness: WORKER=guarded_worker.py python3 incident_repro.py should end with duplicated_task_ids=0 no matter where the kill lands. The checkpoint makes restarts cheap, and the unique key catches the case the checkpoint cannot, such as a rollback after the row was already written.

Progress needs its own signal, so add a dead-man's switch that fires when the heartbeat file stops moving. This is a cron job, not a dashboard nobody reads at 02:14.

#!/usr/bin/env bash
# stale-heartbeat.sh — run every minute
set -eu
HEARTBEAT="${HEARTBEAT_FILE:-/srv/state/heartbeat.txt}"
age=$(( $(date +%s) - $(stat -c %Y "$HEARTBEAT") ))   # macOS: stat -f %m
if [ "$age" -gt 300 ]; then
  curl -fsS -X POST "$ALERT_WEBHOOK" --data-urlencode "text=runner heartbeat stale: ${age}s"
fi

Where a free runner and free models actually fit

This pattern matters most when you do not own the machine, which is exactly the situation on a free tier. MonkeyCode's free model access and free server option are the two pieces that make a nightly batch job cheap enough to run on a box you will never SSH into twice, since the per-item work is a small classification call rather than a frontier request. Disclosure: This article was prepared as part of MonkeyCode's product outreach. Free-tier terms move, so read today's signup page for the current token allotment and server limits instead of trusting a number quoted in any post, including this one.

What the free tier changes is not the engineering, it is the cost of being wrong, because an ephemeral box turns a rare restart into a weekly event. Keep the state in a database you control, point HEARTBEAT_FILE at storage that survives the instance, and the runtime becomes replaceable. If you want to try this before committing any budget, bring up the runner there and leave everything that matters outside it.

Three tests that prove the fix holds

Run the kill test three times in a row, because a single green run tells you almost nothing about a race. Then run two workers concurrently against the same database to simulate duplicate delivery from a queue that at-least-once semantics made inevitable. Finally, delete every row from checkpoints and rerun, which forces the slow path and proves the unique key alone is sufficient.

Symptom in the logs	What it usually means	First thing to check
Worker restarts at item zero	No checkpoint read path exists	Does the checkpoint table get queried?
Row count exceeds queue size	Restart treated as a first run	Is there a unique key on the work id?
Status ok, data wrong	Success written by the worker	Derive status from the rows produced

When this is the wrong tool

Atomic local writes cannot save you when the side effect leaves the database, so if the job sends email, charges a card, or calls a third-party API, you need an outbox and an idempotency key the vendor honours. Checkpointing also stops helping once a single unit of work outlives the maximum instance lifetime, which means the fix there is to split the work rather than to persist harder. And if a lost run is genuinely unacceptable and re-execution is expensive, buy durable compute instead of engineering around a machine that can vanish mid-sentence.

Separate the work from the worker, and the postmortem you write next time will be about something more interesting than a row count.