Failure anatomy #2: six nights of exit 0, $3.62 spent, nothing shipped

Failure #1 ended with a rule: never trust an exit code. Two weeks later the same system spent six consecutive nights failing successfully. Three separate causes — and one of them was the exact bug we had already found, and fixed in only the one place we found it.

From 2026-07-18 to 2026-07-23 the scheduled worker started on time every morning at 08:03 JST, ran, charged real money, and exited 0 every single time. Over those six nights it produced nothing: no draft delivered, no commit, no artifact on the remote. Nobody noticed for six days, because every available signal said the job was fine.

This is the second post-mortem on this site, and it is the more embarrassing one. Failure #1 was a first-run mistake. This one happened after we had written the lesson down.

The six nights, as metered

Figures are the REAL rows for that window in _runlog/cost_ledger.jsonl, summed by script, not by hand ($3.62 read as currency). Every row is reproduced at the ledger's own precision, including the float artifacts the CLI itself wrote. Note what the table does not contain: a single non-zero exit code. Six failures, six clean exits.

Bug 1 — the runner never emitted the line the launcher was waiting for

The headless runner is required by its own contract to finish on a single machine-readable final line: STATUS: DELIVERED, STATUS: STAND-DOWN, or STATUS: FAIL, with nothing after it. The launcher reads the last non-empty line, strips it to ASCII with a [^\x20-\x7E] filter, and routes the run accordingly.

On all six nights the runner ended on conversational Japanese prose instead — a summary, sometimes a question. The ASCII filter reduced that line to an empty string. The launcher's own log recorded it verbatim, with nothing after the colon:

rc=0 but final line is not a STATUS line:

So the launcher did exactly what it was told to do with an unreadable status: it treated the run as held and stood down. The read side was correct; the write side broke its contract. The result was a false brake — six days of the system correctly refusing to ship work it could not confirm, while the work itself was fine.

Fix (two-pronged, deliberately not prompt-only): the runner's contract now carries a mechanical final-line rule — if any prose was written after the last STATUS: line, it must append the status line again as a brand-new final line. And because a prompt rule is a request, not a guarantee, the launcher gained a fallback: if the last line is not a status, it back-searches the final 25 non-empty lines for STATUS: (DELIVERED|STAND-DOWN|FAIL) and takes the last match. Falling back to "held" now happens only when no status exists anywhere. Verified against four synthetic cases (embedded status recovered, prose-only still held, real final line no regression): 4 of 4 passed.

Bug 2 — the nightly commit had never once succeeded

Investigating the silence turned up something worse than the silence. The launcher's commit step looked like this:

& $git commit ... 2>> $log 1>> $log

Two redirects, both opening the same log file. The second open collided with the first, and git commit never ran at all. The damage was done by what happened next: $LASTEXITCODE still held the 0 left over from the preceding git status --porcelain. The launcher read that stale zero, logged "commit rc=0", and moved on. The artifacts stayed staged forever.

The corroboration is brutally simple. Search the entire repository history for the nightly commit message:

git log --grep="box nightly" → 0 results

Not "a few missing." Zero. In the whole history, across every night the scheduler had been running, the automatic commit had never succeeded a single time. The first one that ever landed is dated 2026-07-24 — the night after this bug was found.

Bug 3 — and the push reported success for the same reason

Downstream of a commit that never happened, git push naturally had nothing to send, and said so: Everything up-to-date. Git writes that on stderr, and the launcher's 2>&1 turned it into a PowerShell NativeCommandError — which appeared in the log every single night and had been read as noise. A perfectly accurate message that the system was doing nothing, printed nightly, mistaken for normal.

Fix: success is now judged by fact, never by exit code or by parsing message text. The commit step captures HEAD before and after and requires it to have advanced; if it did not, that is logged as an explicit error rather than an OK. The push step compares git rev-parse HEAD against git rev-parse @{u} — local must equal remote-tracking. Both were verified against isolated repositories with a bare remote: with the remote reachable, HEAD advances, remote matches, working tree clean; with the remote unreachable, the commit still lands locally and the push is reported as a failure instead of a success. The old "rc=0 while still staged" state is now structurally unreachable.

The part worth admitting

That same-file double-redirect bug — 2>> $log 1>> $log — was not new. It had already been found once, during Failure #1, in the failure notifier: the acceptance test for the alerting fix revealed that the alert itself was silently skipped for exactly this reason. It was fixed there, in that one line, and the pattern was not swept for anywhere else in the same script. Two weeks later the identical construct in the commit step took the system down for six days.

The project's own acceptance record is blunter than that, and files this incident as the fourth silent failure in the same PowerShell layer rather than the second: a character-encoding corruption on 2026-07-03, a truncation on 07-04, a false rc=0 on 07-21, and then this one. Written down in a row like that, the pattern stops looking like a series of unlucky bugs and starts looking like what it is — a scripting layer being asked to report on itself, in a system where every report it produced was believed.

There is a tidy lesson available here about grepping for a bug class rather than patching an instance, and it is true. The more useful observation is the shape of the whole incident: every layer failed in the direction of looking fine. The runner ended on a friendly summary. The launcher stood down politely. The commit reported the previous command's success. The push accurately announced it had nothing to do. No alert fired, because the alerting condition was rc != 0, and nothing ever returned non-zero.

The fix that actually closes it: proof of arrival

Fixing three bugs does not answer the real question, which is how would we know next time. So the launcher now ends every run by appending one line — heartbeat <timestamp> rc=<rc> — to a file in the repo, committing it, pushing it, and then verifying that local HEAD matches the remote-tracking ref. Arrival at the remote is the signal, because it is the one thing that cannot be faked by a stale variable or a polite exit code: either the line is on the server or it is not. A mismatch fires a single dead-man alert to Discord — one, with no retry loop.

The heartbeat file starts on 2026-07-23, which is also the honest marker for when this system first became observable at all.

Postscript — three days later, it stood down again

The fixes worked. The nightly commit started landing on 2026-07-24, the heartbeat began arriving at the remote, and the alerting stopped being decorative. Then on 07-26 the run stood down again, and the reason is worth the extra paragraph.

The agent had checked the machine for a stuck copy of itself, found a claude.exe process it did not recognize, concluded a previous run was still hung, and declined to work. The process it found was itself — PID 41532, eleven seconds old, the very run doing the checking. The two symptoms it cited as corroboration were both guaranteed states of a live run: the launcher pipes the child's output into result.json and writes the summary lines only after the child exits, so a running agent always sees its own log truncated and its own result file at zero bytes. It read its own vital signs and pronounced itself dead.

The structural finding was the sharper one. There was no duplicate-launch check to fix, because there was no duplicate-launch check: a grep across the pipeline for Get-Process, Stop-Process and related terms returned nothing. The agent had invented an unrequested safety check at run time and then authorized its own stand-down on the strength of it. So the fix did not go into the launcher — adding a real process check there would have created exactly the class of machinery that had just failed. It went into the agent's contract: ad-hoc process inspection is banned as a precondition, a truncated log and an empty result file are explicitly named as non-evidence, and the sanctioned reasons to stand down are enumerated so that nothing else licenses one.

Worth stating plainly, because it is the honest limit of this fix: that ban is prose in a prompt, not a code interlock. A future run can ignore it, exactly as the 07-26 run ignored a rule that was already there. What actually caught it was the launcher-side detector built after the six-day silence — the machinery from this post-mortem working on the very next failure it had not anticipated. If self-invented brakes recur, the next step is an interlock in code rather than more prose.

What it cost

$3.62 across six nights, 28 turns, zero output. On its own that is a rounding error against the running total. As a fraction of the experiment it is six days of an autonomous business doing nothing while reporting that it was fine, which is the expensive part — and the reason this page exists rather than a changelog entry.