DEV Community

ULNIT
ULNIT

Posted on

My Agent Emailed 200 Customers Twice at 1:30 AM. The Lock File I Added Couldn't Have Stopped It.

At 1:31 AM on the first Sunday of November, my phone buzzed with a customer email that just said: "did you mean to send this twice?"

I read it on the kitchen counter, half asleep, and assumed they meant they'd received last week's digest again — an IMAP sync quirk I'd seen before. Then I opened my laptop and pulled the log.

01:00:04  digest: start
01:00:47  digest: sent 200/200 recipients
01:00:03  digest: start
01:00:48  digest: sent 200/200 recipients
Enter fullscreen mode Exit fullscreen mode

Two complete runs. Both stamped 01:00. Two hundred customers, the same email, an hour apart.

The job is a Sunday account digest: an agent pulls each customer's week, writes three paragraphs in their tone, and sends it through SMTP. It had run cleanly for five months. Nothing in the code had changed. What changed was the calendar.

The bug is older than my project

My crontab entry looked like this, and I had written it without thinking about it for a single second:

0 1 * * 0  sean  cd /srv/agent && /usr/bin/python3 -m agent.digest >> /var/log/digest.log 2>&1
Enter fullscreen mode Exit fullscreen mode

"1:00 AM every Sunday," in the server's local time. On the first Sunday in November, the clocks fall back. The hour between 01:00 and 02:00 happens twice. Cron doesn't know that. It compares wall-clock fields, the wall clock says 01:00 twice, so the job runs twice.

On the second Sunday in March the same entry fires zero times, because 01:00–02:00 doesn't exist at all. I had shipped a job with a scheduled double-send that occurs once a year and a silent no-show that occurs once a year, and I had never once considered either.

Here's the part that still annoys me: my logs made it invisible. I logged with a naive datetime.now(), so both runs wrote 01:00. For weeks afterward, when I searched for duplicate sends, I searched for two different timestamps. There was only ever one timestamp. The evidence was sitting in the log the whole time, wearing a disguise I'd built for it.

What it actually cost

  • 200 duplicate emails, delivered to 200 people.
  • Roughly 30 people got it a third time, because my SMTP sender retried a partial batch on a timeout and the retry re-sent from the top of the list instead of resuming. That's a separate bug, and it was worse than the original one.
  • 41 people opened the second email before my apology landed four hours later.
  • 11 unsubscribes that week, against a baseline of about two.
  • 3 refund requests, all citing "your system is broken," which is fair.

And one genuinely nice email from a customer who said they appreciated the apology being specific about the cause instead of "a technical error occurred." I've thought about that more than the refunds.

My first fix was theater

I did what most of us do: I reached for the tool whose name matched the symptom.

#!/usr/bin/env bash
exec 9>/var/lock/agent-digest.lock
flock -n 9 || { echo "already running"; exit 0; }
exec python3 -m agent.digest
Enter fullscreen mode Exit fullscreen mode

A lock file. flock. The correct, boring, well-understood tool for preventing concurrent runs.

It could not have stopped this. Not in a million years.

The two runs were sixty minutes apart. They never overlapped. A mutex answers exactly one question: is someone running right now? My problem was a different question entirely: has someone already run for this period? Those sound similar and share zero code.

I shipped the lock file, watched it work for a week, updated my notes, and felt fixed. I had fixed the bug I imagined instead of the bug I had. That's the failure I'd put at the top of the list if I were writing this for someone else — worse than the DST bug, because the DST bug was ignorance and the lock file was confidence.

I also tried the obvious one-word fix:

TZ=UTC
0 1 * * 0  sean  ...
Enter fullscreen mode Exit fullscreen mode

Nothing changed. On Debian's cron (which is what Raspberry Pi OS ships), the schedule is evaluated against the system timezone. Setting TZ in the crontab only changes the environment variable handed to the child process — it does not move the schedule. I lost a day to that. CRON_TZ is the variable that does what you want, but only in cronie, not in Debian's vixie-cron, and I was on Debian.

The fix that actually held

Three pieces, none of them clever.

1. Move the machine to UTC and schedule in UTC.

sudo timedatectl set-timezone UTC
Enter fullscreen mode Exit fullscreen mode
# /etc/cron.d/agent-digest
0 8 * * 0  sean  cd /srv/agent && /usr/bin/python3 -m agent.digest --period "$(date -u +\%Y-\%m-\%d)" >> /var/log/digest.log 2>&1
Enter fullscreen mode Exit fullscreen mode

No local time anywhere in the scheduling path. If a human wants it to arrive at 8 AM their time, that's a display concern, not a scheduling concern, and it does not belong in crontab.

2. Make the side effect idempotent on a logical period, not a timestamp.

import sqlite3, datetime as dt

DB = "/var/lib/agent/runs.db"

def claim(job: str, period: str) -> bool:
    """True if this process won the right to run job/period. False if taken."""
    con = sqlite3.connect(DB, timeout=5, isolation_level=None)
    con.execute("PRAGMA journal_mode=WAL")
    con.execute("""CREATE TABLE IF NOT EXISTS runs (
        job TEXT NOT NULL, period TEXT NOT NULL,
        status TEXT NOT NULL, started_at TEXT NOT NULL, finished_at TEXT,
        PRIMARY KEY (job, period))""")
    cur = con.execute(
        "INSERT OR IGNORE INTO runs(job, period, status, started_at) "
        "VALUES (?, ?, 'running', ?)",
        (job, period, dt.datetime.now(dt.timezone.utc).isoformat()))
    return cur.rowcount == 1
Enter fullscreen mode Exit fullscreen mode

The key is (job, "2026-11-01") — the day the work is about, derived from an explicit --period flag or date -u. Not the moment it ran. Two runs an hour apart claim the same key. The second one loses, logs skip: already claimed, exits 0.

Use INSERT OR IGNORE and check rowcount rather than catching IntegrityError; it's atomic under WAL and it doesn't leave a half-open transaction to reason about.

One refinement that matters: a running row that never gets a finished_at is a crash, not a duplicate, and you don't want it to block next week's run forever. I added a 6-hour staleness rule — a running claim older than that is treated as abandoned and can be re-claimed.

3. Alert on the business invariant, not the process exit code.

My old health check asked "did the job log a success line in the last 25 hours?" Both runs did. Green, green, green.

The new one asks a question about the world:

SELECT COUNT(*) FROM sends
WHERE job = 'digest'
  AND sent_at > datetime('now', '-1 day');
Enter fullscreen mode Exit fullscreen mode

If that number is more than 1.05× the subscriber count, page me. It doesn't care how the duplicate happened — cron, a retry loop, a manual run, a restore from backup. It only cares that 200 people were supposed to get one email and the system sent 400.

Every alert I have now is phrased as "a customer-visible number is wrong," not "a process failed."

Before you close this tab

If you run anything on a schedule that touches money, email, or other people's inboxes, do this in the next twenty minutes:

  1. grep -r "" /etc/cron* and list every entry whose schedule isn't in UTC. Fix the timezone, not the expression.
  2. For each one, write down the logical period the job operates on. If you can't name it in one word (daily, 2026-W44, a billing cycle ID), you don't have an idempotency key yet.
  3. Run it twice on purpose, back to back, and confirm the second run does nothing. If it does something, you have a double-send waiting for a DST boundary, a retry, or a deploy restart.
  4. Check your retry logic separately. Mine re-sent from the top of the list instead of resuming, which is how 30 people got a third copy. Retries need the same key as the original run, or they're a duplicate generator with extra steps.
  5. Ask what your monitor would have said. If the answer is "it would have been green," your monitor is measuring the process and not the promise.

The DST bug was a one-line crontab mistake. The reason it survived five months and hurt 200 people is that I had no way to tell "the job ran" apart from "the job did the right thing exactly once," and I never noticed the difference until the calendar forced me to.

I rebuilt my pre-launch review after this, because the same blind spot — a check that confirms the process exited zero while the outcome is wrong — is how a lot of launch-day problems survive testing. The full checklist + scripts are in Ship Safe — The Launch-Day Security Kit — code LAUNCH90 at checkout makes it $1.50.

Top comments (0)