Fixing a Python fromisoformat Error Unmasked a Stale Alarm That Had to Fire

Originally published on hexisteme notes.

At 21:00 on October 9, and again at 09:00 the next morning, the snapshot job in my agent telemetry pipeline raised this alert:

F3-SOURCE-CHECK-ERROR: argument --since: not an ISO-8601 timestamp: '1970-01-01T00:00:00Z'

The alert's wording pointed at suspected loss of the raw archive. Nothing had been lost. The archive copy was working, and its newest file was from 08:59 that morning. What failed was a source-freshness check inside the same job. The parse error was the easy part; what it had been covering up was the real lesson.

Python 3.9 and a trailing Z

Under cron's PATH, python3 resolved to /usr/bin/python3, which is 3.9.6. Before 3.11, datetime.fromisoformat does not accept a trailing Z, and the job passes --since 1970-01-01T00:00:00Z. My interactive shell runs 3.13, so nothing reproduced by hand. The argument was not the only casualty: 540 of the 541 ended_at values in the database also end in Z, so under 3.9 the parser would have read none of them.

The fix is a small wrapper, _fromisoformat(), that rewrites a trailing Z or z to +00:00 before parsing; both the database and CLI parsers use it. The test that matters, test_cron_interpreter_reads_z_suffix_timestamps, runs the module under the cron interpreter (PAMSL_PY, defaulting to /usr/bin/python3), not the Python running pytest. It reproduced the error before the fix and passed after. The suite passed at 143 on 3.13, and the cron command, run verbatim, exited 0.

An earlier note, The Scheduled Step Failed on Night One. The Heartbeat Stayed Green., covers how a bare python3 resolves to Apple's system Python under launchd's PATH while a fail-soft step keeps the heartbeat green. That failure was silent. This one was loud, named the wrong problem, and sat on top of a second one.

What the parse error was covering

The job's alert function writes each message into a single flag file, replacing whatever was there. Once the parser worked, the next run would put this in its place:

F3-SOURCE-STALE source_data_age_seconds=771145.565 newest_ended_at=2026-10-01T11:46:44.435000Z: Claude record files newer than newest ended_at exist; DB lags source

771,145 seconds is just under nine days. I read it as a real alarm and left the flag in place while I looked for the cause.

There was no broken build. The database is rebuilt only by the weekly report job, Mondays at 09:30. The October 5 build exited 0 and loaded all 541 top-level files then in the archive. The 76 files not in the database (617 archived minus 541 loaded) all belonged to sessions that started after that build. The database was exactly as current as a weekly design promises.

The newest session inside it, though, had ended on October 1 at 11:46 UTC. Between September 20 and October 5 there were only four Claude Code sessions, because most of my agent work had moved to Codex (see Our LLM Telemetry Stayed Green While the Work Moved to Codex). So the October 5 build came after a quiet gap of 3 days, 12 hours and 43 minutes.

Why that alarm had to fire

The rule was: STALE if the newest ended_at is more than 8 days old and Claude record files newer than it exist. The build runs every 7 days. On build day the newest loaded record is already as old as the quiet gap before it, and it ages all week. If that gap exceeds one day, the record crosses 8 days before the next build, and any work done since supplies the newer files. The STALE condition is then certain to come true before the next build. It stays true for roughly the gap minus one day, and whether a scheduled check catches it depends on how that window lines up with the check times.

This time the STALE window ran from 20:46 KST on October 9 until the build at 09:30 KST on October 12. Both failed runs fell inside it. The parse error had been hiding an alarm that would have fired on both of those runs and kept firing until Monday.

The second condition makes it worse. With no new activity, the same rule reports INACTIVE and stays quiet. What tripped it was going back to work.

Measuring the wait instead of the newest record

The Codex note describes the opposite failure in this pipeline: a staleness check keyed to when the database file was last rewritten, which a weekly rebuild always satisfies, so it stayed green while the newest session inside was ten days old. That note closed by recommending a freshness check on the gap between the newest ingested session and the report date. The checker here did exactly that, and test_db_file_mtime_is_not_freshness keeps a freshly rewritten file with old data from reading as FRESH.

Newest-record age answers "when did the data last move?" In a store loaded in weekly batches, that depends on when I happened to stop working before the last batch. The question I wanted answered was "has anything waited too long to be loaded?"

So the definition changed. The check takes the record files modified after the newest ended_at (plus a five-minute grace for that session's own last write) and measures how long the oldest of them has waited: unreflected_wait_seconds. Those files are a proxy for what the database has not loaded yet. When the newest ended_at is more than 8 days old, STALE now also requires that wait to exceed 8 days. If such files exist but none has waited that long, the status is AWAITING_BUILD, which does not alert. A quiet gap before a build no longer trips the alarm; a file has to sit newer than the loaded data for longer than the threshold. The alert line also prints unreflected_wait_seconds=.

Three existing tests were rewritten to the new meaning, and a new one replays October 10: newest ended_at on October 1, first file after the build at 00:58 UTC on October 5, source age over 8 days, expected AWAITING_BUILD. The suite passed at 145, and the shared telemetry environment check passed. The cron command, run verbatim under 3.9, exited 0 with no alert: AWAITING_BUILD, 299 record files waiting, the oldest for 5.37 days, newest-record age 8.94 days. Those are record files, not sessions; one session spans several files. With both causes resolved, I deleted the alert flag.

A read-only query that wasn't

I caused one more failure during the investigation. I queried the database directly with Python's sqlite3 and a file:...?mode=ro URI. The database runs in WAL mode, and that read left a 0-byte -wal file and a -shm file beside it. The checker refuses to read while a -wal file exists, so the next check reported DB_UNAVAILABLE (active WAL present). I confirmed no process had the database open and deleted both files.

On a copy, mode=ro created both sidecar files and immutable=1 created neither. The checker already opens with immutable=1, and a test verifies that its read of a WAL-mode database leaves the directory unchanged; my hand-typed query skipped that. Direct queries now use ?immutable=1. This is what happened on this machine with this database. I have not checked it against SQLite's documentation, so it is not a general claim about SQLite.

What this does not prove

• The evidence stops on October 10. The record documents one cron run of the new rule against real data, and it does not show what the check printed after the October 12 build.
• The new rule is quieter on purpose. A new record file can now wait up to 8 days to be loaded with no alert. In the alert mode the cron job uses, AWAITING_BUILD prints nothing; the wait is still recorded in the JSON report.
• The wait is measured from file modification time, which the module itself calls a proxy: the last write to a file, with its contents unread.
• In the code, the link between the 8-day threshold and the 7-day build is a comment beside the constant. If the build cadence changes, the threshold has to change with it by hand.
• _fromisoformat() handles a trailing Z or z and nothing else, and the job still runs on the 3.9 system interpreter. Whatever else differs between 3.9 and 3.13 will surface either in a test that runs the module under that interpreter or in the scheduled run itself.

Email list for these notes: hexisteme.beehiiv.com — no issue has gone out yet, so you would be on it before the first one. No welcome sequence, no course, no upsell.

More notes at hexisteme.github.io/notes.