From ff77a23162c33986ae1a4aab45b1b8de2ca0224e Mon Sep 17 00:00:00 2001 From: Christopher Pitzi Date: Mon, 17 Aug 2026 18:42:26 -0400 Subject: [PATCH] =?UTF-8?q?docs:=20game-day=20#1=20post-mortem=20=E2=80=94?= =?UTF-8?q?=20runner=20kill,=2084s=20self-heal,=20detection=20gap?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-Authored-By: Claude Fable 5 (1M context) --- fleet-reports/incidents.md | 5 +- .../2026-08-17-gameday-1-runner-kill.md | 48 +++++++++++++++++++ 2 files changed, 51 insertions(+), 2 deletions(-) create mode 100644 fleet-reports/incidents/2026-08-17-gameday-1-runner-kill.md diff --git a/fleet-reports/incidents.md b/fleet-reports/incidents.md index e405e09..c42d59e 100644 --- a/fleet-reports/incidents.md +++ b/fleet-reports/incidents.md @@ -3,12 +3,13 @@ > [!NOTE] > **Co-authored with [Claude](https://claude.ai)** (the `/incident-digest` playbook). A chronological register of incident reports harvested from local Lentago lab activity and published as a periodic fleet report. Each row links to the full write-up under [`fleet-reports/incidents/`](incidents/). Unlike the [fleet report](fleet-report.md), these are published **verbatim** and *do* include homelab-internal architecture detail — but never credentials, keys, or secrets. -**Generated:** 2026-08-17 18:37 UTC · **23 incidents logged.** +**Generated:** 2026-08-17 22:42 UTC · **24 incidents logged.** -**Deployment-caused:** 10 yes · 12 no · 1 unknown — the DORA change-failure-rate / failed-deployment-recovery-time inputs; each report's `Deployment-caused` marker feeds this line. +**Deployment-caused:** 10 yes · 13 no · 1 unknown — the DORA change-failure-rate / failed-deployment-recovery-time inputs; each report's `Deployment-caused` marker feeds this line. | Date | Incident | Deploy-caused | Summary | |------|----------|:---:|---------| +| 2026-08-17 | [Game-day #1: killing a bullpen runner mid-job — the queue healed itself in 84 seconds, and nothing told anyone](incidents/2026-08-17-gameday-1-runner-kill.md) | No | We killed a claytonia worker (pct stop on LXC 117, claude-runner-5) 94 seconds into a real job, with a pre-registered hypothesis: the queue's stale-heartbeat reaper should requeue the orphan within 90–150s, a second worker should finish… | | 2026-08-12 | [The watcher readable by the watched: closing the myosotis exposure window on org-opening day](incidents/2026-08-12-myosotis-exposure-window.md) | No | The lentago org was repurposed on 08-12 as a learning lab for IT-ops colleagues — invites out, one already accepted. | | 2026-08-12 | [The gate that dropped a guard on the way up: merge-gate rollout's silent allowance loss](incidents/2026-08-12-merge-gate-silent-allowance-drop.md) | Yes | Sweeping the newly opened org, the operator asked to gate every merge to main on an org owner/admin. | | 2026-08-09 | [Auto-merged red: a dropped brace, a non-required check, and four minutes of broken main](incidents/2026-08-09-claytonia-automerged-red.md) | Yes | During the myosotis visibility-layer work, claytonia PRs #86 and #87 both appended tests to the tail of test/context-ledger.bats. | diff --git a/fleet-reports/incidents/2026-08-17-gameday-1-runner-kill.md b/fleet-reports/incidents/2026-08-17-gameday-1-runner-kill.md new file mode 100644 index 0000000..26519dc --- /dev/null +++ b/fleet-reports/incidents/2026-08-17-gameday-1-runner-kill.md @@ -0,0 +1,48 @@ +# Game-day #1: killing a bullpen runner mid-job — the queue healed itself in 84 seconds, and nothing told anyone + +Compiled 2026-08-17 from the live exercise (asclepias Lab 04 format; first scheduled game day, maintainer-coordinated). + +**Deployment-caused:** no + +--- + +## TL;DR + +We killed a claytonia worker (`pct stop` on LXC 117, claude-runner-5) 94 seconds into a real job, with a pre-registered hypothesis: the queue's stale-heartbeat reaper should requeue the orphan within 90–150s, a second worker should finish it, the dashboard should show the loss, and **no alert should fire because none exists**. All four predictions held — recovery was fully autonomous (kill → reclaimed by claude-runner-2 in **84s**, second run finished clean, worker rejoined **20s** after `pct start`) — and the detection gap is now a filed workstream, not a suspicion. + +## The contract under test + +claytonia's queue README promises: workers heartbeat `workers/.alive` every 30s; `process-inbox` reaps `processing/` entries whose owner is >90s stale, requeues once (`.retry`), fails them if stranded twice. At-least-once delivery; claim is an atomic rename. + +## Timeline (UTC, 2026-08-17) + +| T | Event | +|---|---| +| 22:34:09 | Sacrificial ad-hoc job dispatched (no repo side effects by design) | +| 22:34:12 | Claimed by **claude-runner-5** (atomic mv → processing/) | +| 22:35:49 | **T0 — `pct stop 117`** mid-job (94s into the run) | +| 22:37:13 | Reaper requeues the orphan as `.retry` | +| 22:37:14 | **Reclaimed by claude-runner-2** — 84s after the kill | +| 22:37:43 | `pct start 117` (recovery begins) | +| 22:38:03 | runner-5 heartbeating again — 20s | +| 22:39:11 | Retry run completes, exit 0 ($0.11, 118s). `failed/` stays empty | + +## Hypothesis vs. reality + +1. **"Requeue in 90–150s from the kill" — held, and taught a precision lesson.** Actual: 84s, *below* the predicted lower bound — because the staleness clock runs from the last heartbeat, not from the failure. The worker had last heartbeated ~35s before the kill, so the reaper's 90s window had a head start. Failure-detection latency is bounded by `staleness + poll cadence` measured from the last proof of life, not from the fault. +2. **"A second worker finishes the job" — held.** Clean handoff, single `.retry`, exit 0, nothing stranded. +3. **"Nothing alerts" — held, which is the finding.** The Runner Fleet dashboard showed the drop for anyone watching; no rule watches worker liveness or `.retry` events, so an unwatched dashboard was the entire detection surface. Filed as drosera#207. +4. **"Recovery is one command" — held.** `pct start`, 20 seconds to rejoin, no queue surgery. + +## What the archive volunteered + +Grepping `logs/` for `.retry` artifacts turned up two from 2026-07-08 — the reaper has already fired **in real production**, unnoticed, during the music-curator research waves. One of those retries even exercised the documented at-least-once boundary: the retried job found its predecessor's PR already open and stopped itself. Self-healing that works silently is the best argument for absence-alerting: the mechanism has been saving us without telling us. + +## Residual findings + +- A killed run leaves 0-byte `logs/.{json,stderr}` stubs from the dead worker. Cosmetic, but tooling that scans `logs/` should not read an empty stub as a completed run. +- The kill window matters: this exercise severed the worker *before* any PR push. A kill after branch-push but before PR-open is the nastier at-least-once case — the July chunk-10 retry shows the workers handle the duplicate-PR flavor of this, but it deserves its own game day. + +## Governance lesson + +The queue's crash recovery was CI-tested before tonight (bats harness, claim-by-rename races) — and the live exercise still earned its keep: it measured the actual numbers, surfaced the detection gap the tests can't see (tests assert recovery *happens*, not that humans *hear about it*), and pulled two unnoticed production recoveries out of the archive as corroboration. The register publishes all of it verbatim, per standing policy.