Files
felhom.eu/documentation/tests/campaign10-evidence-2026-07-31/r157-bootrecon-start-once-race.md
T
admin 3d4c5365c1 Campaign 10: correct R-157 — the failure is INTERMITTENT (3 of 6), not deterministic
The first write-up said R-157 reproduced "at the same cycle in both runs -
deterministic, not a coincidence". Wrong. The cycle numbers matched only because
the runner's RNG is seeded so both runs drew the same permutation. The failure
itself is a coin flip: run 2b's four hard resets went PASS(c2), FAIL(c10),
PASS(c18), FAIL(c26); run 2a went PASS(c2), FAIL(c10). Three failures in six.

The correction matters because it changes what kind of bug this is, and it
strengthens rather than weakens the root cause: intermittency is exactly what a
race against container-state settling predicts, whereas a wrong predicate would
fail every time.

Signature is identical on all three occurrences: rallly Exited 255 with
rallly-postgres healthy, bootrecon reporting "no boot-orphaned apps" about 5s
after controller start, and the container count still churning after the sweep
(third occurrence 01:05: refresh 8, bootrecon 01:05:13, then 8 -> 7 -> 8).
2026-08-02 03:17:03 +02:00

6.2 KiB

R-157 — bootrecon's start-ONCE sweep acts on an unsettled snapshot, so the boot orphan it exists to recover survives

INTERMITTENT — 3 failures in 6 hard resets (~50%), across two independent runs. Controller 0.188.0, agent 0.119.0.

Correction to this document's first version. It said the failure reproduced "at the same cycle in both runs — deterministic, not a coincidence". That was wrong, and the correction matters because it changes what kind of bug this is. The cycle numbers matched only because the runner's RNG is seeded, so both runs drew the same permutation; the failure is a coin flip. Run 2b's four hard resets went PASS (c2) → FAIL (c10) → PASS (c18) → FAIL (c26), and run 2a went PASS (c2) → FAIL (c10). Intermittency is what a race predicts — a wrong predicate would fail every time — so this strengthens the root cause below rather than weakening it.

R-52 built internal/bootrecon for exactly this failure (audit F5: immich-server and calibre-web left Exited after an interrupted boot, ten siblings back, those two still down ~18 h later"the controller REPORTED them (the 30 s deadapp-check) but never started them"). This is that failure recurring through a timing hole in the fix.

What happened

Cycle 10's permutation ran hard_reset_mid_write — a qm reset of the VM during a backup. Everything came back except the app half of the DB-backed stack:

rallly Exited (255), oom=false, no error string, restarts=0
rallly-postgres Up (healthy)
every other app back and healthy, both drives bound
rallly's own last log line ▲ Next.js 16.2.6 … ✓ Ready in 0ms — it died healthy

The controller start-up sequence, verbatim:

20:28:13 [stacks] ScanStacks complete: 55 stacks found (5 deployed, 50 available)
20:28:13 [stacks] Status refresh: 8 containers across 55 stacks
20:28:18 [bootrecon] Boot reconciliation: no boot-orphaned apps (nothing to start)
20:28:24 [stacks] Status refresh: 8 containers across 55 stacks
20:28:25 [stacks] Status refresh: 7 containers across 55 stacks     <-- still churning
20:28:25 [stacks] Status refresh: 8 containers across 55 stacks
20:29:44 Event pushed: app_start_failed (warn) — Telepített alkalmazás nem fut: Rallly
20:39:14 [deadapp] check alive: 20 scans since boot, 5 deployed app(s) evaluated, 1 currently down

docker ps -a reports 9 containers; every Status refresh reports 8. The controller's boot-time snapshot is one short, and the missing one is the exited rallly.

Why this is a defect and not the documented safety boundary

bootrecon deliberately never touches a stack the customer stopped, and the predicate for that is sound (bootrecon.go:100):

len(s.Containers) > 0 && stacks.IsDownState(s.State)

Both terms hold for this stack once the system settles — the controller's own API now reports:

rallly  state=degraded  deployed=true  containers=2
          rallly           exited    Exited (255)
          rallly-postgres  running   Up (healthy)

IsDownState includes StateDegraded (manager.go:55), and len(Containers) is 2. So the predicate was never the problem. The snapshot was. bootrecon fires as go runBootReconcile(...) at cmd/controller/main.go:236, ~5 s after start, while docker is still bringing containers back — and it is start-once by design, so it never re-evaluates.

Two mechanisms are consistent with the evidence and this report does not claim to distinguish them:

  1. the exited container was not yet enumerated, so the stack looked running (1/1) rather than degraded (1/2) — supported by the 8-of-9 count; or
  2. the stack's state had not yet aggregated to degraded at that instant.

Either way the root is the same: a single observation taken before the system settles, with no re-check.

Consequence

The app stays down indefinitely. Detection works perfectly and recovery never happens — the deadapp check correctly counted 1 currently down across 20 scans / 10 minutes, and app_start_failed reached the customer. In run 2a the app only returned because a later campaign atom happened to redeploy the stack; nothing in the product recovered it.

This is the R-52 failure shape exactly: an alarm with no recovery.

Why it is not a harness artifact

The preceding two violations in this campaign were harness defects and are documented as such (run2a-violations-were-harness.md). This one is not:

  • both drives were bound (adatok: True, mentes: True), so no drive gate stopped anything;
  • every other app returned, including calibre-web, whose data is on an enrolled drive;
  • only the app half of a two-container stack is missing, while its database is healthy;
  • the fixed harness reported it through the check written for precisely this ("apps did not return within 10 min — that IS the failure"), not through a seed or canary path;
  • it recurred 3 times out of 6 hard resets with an identical signature every time: rallly Exited (255) with rallly-postgres healthy, bootrecon reporting "no boot-orphaned apps" ~5 s after start, and the container count still churning after the sweep. Third occurrence (2026-08-02 01:05): Status refresh 8 → bootrecon at 01:05:13 → refresh 8 → 7 → 8 at 01:05:19-20.

Shape of a fix — not applied (the fences forbid it, and a fix mid-run proves a version that did not exist)

The bounded start-once property is the safety argument and should be kept. What is missing is a settle condition before the one observation: wait for the container set to stop changing (or for docker to report ready) before the sweep, or re-evaluate once at the end of deadAppBootGrace and recover then, still bounded to the same total attempts. A test would pin the consequence — an app left Exited by an interrupted boot is running again before the grace expires — rather than the mechanism, per the workspace rule about invariants needing a test that fails when the dependency moves.

Register

R-52 is the feature; grep found no existing item covering its timing. R-156 is this campaign's papra finding. R-157 is free and is claimed here.