C9-F1 + C9-F2: a restore that restored nothing, and a crash loop nobody saw (v0.183.0)

Both are the system reporting healthy while the customer is not, and both live in the same
status-derivation code. Neither is fixed by making the system quieter.

C9-F1 (HIGH) — Tier-2 writes recovery-unit/ on EVERY run and RestoreTier2Files has never read
it (tier2_restore.go:101-104 reads hdd/ + userdata/ only). Phase 0 enumerated all 53 catalog
templates against both demo boxes: 43 apps have NO readable subtree, so the button stopped the
app, restored 0 files, restarted it and said "Nincs hiányzó fájl — minden fájl megvan a helyén."
— at the moment the customer pressed it because files were missing, with 156 MB of BookStack's
data unread in the same copy. 9 apps have file legs but never their DB or volumes, so the same
sentence was also a clean bill of health over data never opened (immich: 1.3 GB Postgres unit).

Honesty half shipped: a pre-flight coverage check refuses UP FRONT without stopping the app and
NAMES the action that works; a run that proceeds claims only what it EXAMINED and discloses that
the database and volumes are not covered. Completeness is filed as C9-F1b — routing to the
Tier-1 unit restore puts a destructive operation behind a non-destructive button, so its confirm
copy has to carry that difference. C9-F4 filed: nothing reads the Tier-2 recovery-unit/ mirror,
so the second local copy that exists for drive loss is unreachable by any customer action.

C9-F2 (HIGH) — a crash loop was counted as working. StateRestarting is deliberately NOT added to
IsDownState (that alarms on every deploy fleet-wide, the over-correction F-A1 nearly cost us); a
sustained run becomes down after crashLoopAfter = 5m, set above the 120s deploy timeout, Mealie's
60s start_period and R-97b's 180s grace. The dashboard counter uses the same predicate, so it no
longer contradicts the alarm on the same screen. README's claim that faults "still surface as
restarting" was a wish with no test — corrected in place; it is the seventh such instance.

Six red-proofs observed, including the one that matters most: adding StateRestarting to
IsDownState fails the brief-restart test with "every deploy and update would page the operator".
go test ./... rc=0, 27 packages, run and read separately from this commit.
This commit is contained in:
2026-07-28 18:53:56 +02:00
parent d8b3279731
commit fd50a73e65
12 changed files with 805 additions and 38 deletions
+67
View File
@@ -55,6 +55,54 @@ func IsDownState(s ContainerState) bool {
return s == StateStopped || s == StateExited || s == StateDegraded
}
// C9-F2 — a SUSTAINED `restarting` is a crash loop, and a crash loop is a dead app.
//
// THE BUG THIS EXISTS TO KILL. `IsDownState` above excludes `restarting` as "self-recovering", and
// for a brief restart that is exactly right. But Docker sets `restarting` while a container is being
// restarted BY POLICY, and for the catalog's standard `restart: unless-stopped` that is precisely the
// crash-loop signal — the retry count is unlimited, so "self-recovering" is a promise Docker never
// made. Campaign 9 watched docmost loop for nine minutes (restartcount 18, policy `unless-stopped`)
// while the F-OBS heartbeat printed "180 scans since boot, 4 deployed app(s) evaluated, 0 currently
// down". No banner, no app_start_failed, no email, no hub event — indefinitely.
//
// This is CONTEXT.md's own lesson one state over: "Docker's .State says 'running' even for unhealthy
// containers — must parse .Status". Same trap, different state, and this state means something worse.
//
// ── WHY A THRESHOLD AND NOT A DOWN-STATE ─────────────────────────────────────────────────────
//
// Adding StateRestarting to IsDownState would alarm on every deploy and every update, fleet-wide,
// because the normal `docker compose up -d` path passes through `restarting`. An alarm that fires on
// routine operations is one the operator learns to ignore — which is what F-A1 nearly cost us right
// after R-97a built it. So `restarting` becomes down only once it has PERSISTED.
//
// ── WHERE 5 MINUTES COMES FROM ───────────────────────────────────────────────────────────────
//
// Measured against the three real numbers already in this codebase, not picked round:
// - the deploy flow allows **120 s** for a stack to come up healthy — the project's own existing
// answer to "how long is too long"; an app still restarting past it has failed deployment;
// - the slowest catalog healthcheck start_period is Mealie's **60 s**, after which a couple of
// check intervals must still elapse before any verdict is meaningful;
// - R-97b's quiesce grace is **180 s**, and this must sit ABOVE it so the two windows compose into
// one bounded delay rather than a gap where an app is un-suppressed but not yet sustained.
//
// 300 s clears all three with margin. It is also unambiguous against Docker's own backoff, which
// grows 100 ms → 200 ms → … and caps at 60 s: a genuine crash loop registers at least four restart
// attempts inside this window, so a stack that is still `restarting` at 5 minutes is not mid-deploy.
//
// The cost is a bounded DELAY in reporting a real crash loop, never its loss — the same trade R-97b
// made deliberately, and the opposite of the indefinite silence this replaces.
const crashLoopAfter = 5 * time.Minute
// CrashLooping reports whether the stack has been `restarting` for longer than crashLoopAfter.
// `now` is injected so the rule is a unit-testable contract rather than a property of the clock.
// A zero RestartingSince means "not restarting, or not yet observed restarting" — never a crash loop.
func (s *Stack) CrashLooping(now time.Time) bool {
if s == nil || s.State != StateRestarting || s.RestartingSince.IsZero() {
return false
}
return now.Sub(s.RestartingSince) >= crashLoopAfter
}
// ContainerInfo holds status info about a single container within a stack.
type ContainerInfo struct {
Name string `json:"name"`
@@ -95,6 +143,13 @@ type Stack struct {
DeployError string `json:"deploy_error,omitempty"` // last async deploy error
HealthProbe *HealthProbeResult `json:"health_probe,omitempty"` // controller-side probe result
LastUpdated time.Time `json:"last_updated"`
// RestartingSince (C9-F2) is when this stack was FIRST observed in StateRestarting during the
// current restarting run; zero whenever the stack is in any other state. It is what turns a brief
// restart (normal: deploy, update, quiesce restart) into a distinguishable crash loop — see
// CrashLooping. Not persisted: a controller restart re-observes the state within one refresh, and
// forgetting costs at most one threshold window, whereas persisting could carry a stale
// "this app is crash-looping" verdict across the restart that fixed it.
RestartingSince time.Time `json:"restarting_since,omitempty"`
}
// Manager handles all docker compose stack operations.
@@ -587,6 +642,18 @@ func (m *Manager) refreshStatusLocked() error {
stack.State = StateUnhealthy
}
// C9-F2: stamp the start of a restarting RUN, and clear it the moment the stack is anything
// else. Set AFTER the health-probe override above so the stamp always agrees with the state
// that is actually stored. Clearing on any other state is what keeps a normal deploy — which
// passes through restarting briefly — from ever accumulating toward the threshold.
if stack.State == StateRestarting {
if stack.RestartingSince.IsZero() {
stack.RestartingSince = time.Now()
}
} else {
stack.RestartingSince = time.Time{}
}
if m.isDebug() {
m.logger.Printf("[TRACE] [stacks] refreshStatusLocked: stack %q → state=%s containers=%d", name, stack.State, len(stack.Containers))
}