admin
3d4c5365c1
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).
110 lines
6.2 KiB
Markdown
110 lines
6.2 KiB
Markdown
# 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.**
|