diff --git a/CHANGELOG.md b/CHANGELOG.md index 141afcc..499f91a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,51 @@ ## Changelog +### v0.177.0 — R-97: a failing backup is HEARD, and stops blaming the apps (2026-07-27) — MinAgent unchanged; requires hub >= v0.78.0 + +**R-97a — the whole-guest tier had no route to the hub.** `internal/quiesce` did not import +`internal/notify` at all, so on 2026-07-27 three failed whole-guest backups and twelve app-stack +stop/starts produced **zero** events. `NotifyBackupFailed` existed and the hub allowlisted +`backup_failed`; only the wiring was missing — the inert-seam shape this project has now hit five times. + +This got MORE urgent when R-88 shipped, not less. Before the breaker a failing backup retried every +5 minutes: harmful, but loud enough to notice. Now it backs off to 4h and goes quiet, leaving the +hub's deadline monitor as the only signal — **~26h for local, ~8 days for PBS**, a full cycle of the +weekly tier. This trades that delay for an immediate one. + +`quiesce.TierNotifier` is a seam, not an import (same reason `windowStartFn` is injected), wired by +the init-only `SetTierNotifier` because main.go builds the notifier *after* the loop. It is +**edge-triggered**: `BackupFailed` fires when the breaker ARMS — the first failure of a run, never +the retries behind it — and `BackupRecovered` on `recordSuccess`'s existing bool, so an operator told +a tier broke is also told it healed. + +**New OPERATOR-ONLY event types**, `whole_guest_backup_failed` / `_recovered` (hub v0.78.0). +Deliberately NOT `backup_failed`: that type carries a customer-facing Hungarian template **and** sits +in demo-felhom's live `enabled_events`, so reusing it would have emailed the CUSTOMER +„A biztonsági mentés sikertelen" while the backup was still retrying. The tier travels in +`WholeGuestBackupDetails.Tier`, which is load-bearing — the hub keys its per-tier operator cooldown +on it, so `local` failing is not swallowed by `felhom-pbs` having failed within the hour. + +**R-97b — stop telling the customer their app is broken when WE stopped it.** During the loop the only +customer-visible output was `app_start_failed — „Telepített alkalmazás nem fut: BookStack"`: customer +channel, Hungarian, during an outage the backup system itself caused, with no indication why. + +**v0.164.0's filter does not cover this.** That predicate is state-based +(`IsDownState(st.State) && st.State != StateStopped`) and suppresses *deliberately stopped* apps. +BookStack alarmed because the third cycle caught it **mid-restart** — starting, or up but not yet +healthy — which is not `StateStopped`. No state classification can tell "restarting because a backup +stopped me" from "restarting because I keep crashing"; the distinguishing fact is that *we* stopped +it, and we know we did. So the fix is a **suppression window keyed to the cycle**, consumed at the +same single derivation point (`classifyRunStates`) that already computes both the banner dead-list +and the notifier Down-set — still one place. + +**The grace window is 180 s**, derived rather than picked round: the deploy flow already allows +**120 s** for a stack to come up healthy, and the slowest catalog healthcheck start_period is Mealie's +**60 s**, after which a couple of check intervals must still elapse. It **expires** — an app that +genuinely fails to come back alarms on the first scan after the window closes. Permanent suppression +would trade a loud false alarm for a silent real one, which is R-88's Scenario D in a new costume. + +Tests +9 (8 quiesce + 1 wiring reachability). Red-proofs observed for Scenarios C, E and F. + ### v0.176.0 — R-88 Part 1: a failing backup stops re-quiescing (2026-07-27) **The apps were being stopped and restarted every five minutes for a backup that could not diff --git a/REUSE.md b/REUSE.md index 094d8a3..8973185 100644 --- a/REUSE.md +++ b/REUSE.md @@ -74,6 +74,8 @@ | `Loop.writeMarker` / `Recover` | controller/internal/quiesce/quiesce.go | `(m Marker)` / `()` | Quiesce crash-safety | Marker written BEFORE stopping stacks; Recover restarts stranded stacks at boot | | `quiesce.TieredBackend` + `Loop.resolveDueTiers` / `quiesceAndPollTiers` | controller/internal/quiesce/tiers.go, quiesce.go | `Tiers/DueFor/StartBackupFor/BackupStatusFor`; `resolveDueTiers(ctx) ([]dueTier,bool,error)` | THE R-82 multi-tier backup schedule — several whole-guest tiers (local daily + PBS weekly) reconciled into ONE quiesce window | **Both tiers due ⇒ ONE stop/start pair**, never two (two = two app outages for one night). Tiers run SEQUENTIALLY (vzdump holds a guest lock) and the app stays down until the LAST tier snapshots — resuming earlier loses app-consistency on the DR tier. Order is fast-first (agent advertises primary first) or downtime blows up. `ErrTiersUnsupported` (route 404) ⇒ pre-R-82 agent ⇒ degrade to the untargeted path and **STILL BACK UP** — never read it as "nothing due". | | `quiesce.failureBreaker` + `Loop.dropBackedOffTiers` / `noteTierFailure` / `noteTierSuccess` | controller/internal/quiesce/breaker.go, quiesce.go | `blocked/recordFailure/recordSuccess(target, now)`; `backoffFor(n) time.Duration` | **R-88** — a tier whose backups keep failing stops re-quiescing. Backoff 15m→30m→1h→2h→4h (cap), reset on success | **It gates the QUIESCE, not the backup** — the harm was never the failing backup, it was the app outage taken to attempt it, so backed-off tiers are dropped from the due set BEFORE any stack is stopped. **Per TARGET** — a broken offsite tier must never suppress a healthy local one (`TestBreaker_OneFailingTierDoesNotSuppressAHealthyOne`). **Never permanent** — the cap bounds the retry INTERVAL, it never stops retrying; a latched breaker is a silent backup outage, worse than the loop it replaces. **`TriggerNow` is never gated** (it already bypasses due-ness and the window gate), though a manual run still RECORDS its outcome. **`stillRunning` is NOT a failure** — a first full offsite snapshot legitimately runs for hours. State is **in-memory on purpose**: a restart forgets the backoff and re-attempts, which is the cheap direction to fail. Log the deferral ONCE when armed, never per tick. | +| `quiesce.TierNotifier` + `Loop.SetTierNotifier` / `noteTierFailure` / `noteTierSuccess` | controller/internal/quiesce/breaker.go, quiesce.go | `BackupFailed(tier,msg,err)` / `BackupRecovered(tier,msg)`; `SetTierNotifier(n)` INIT-ONLY | **R-97a** — the whole-guest backup tier reports its outcome to the hub | A **seam, not an import** — quiesce keeps no dependency on `internal/notify` (same reason `windowStartFn` is injected). Wired by a setter because main.go builds the notifier AFTER the loop; `nil` = unprovisioned guest, not an error. **Edge-triggered:** failure fires only when the breaker ARMS (`n == 1`), never per retry — the cadence is 15m/30m/1h/2h/4h and an event per attempt is an inbox nobody reads. Recovery rides `recordSuccess`'s existing bool. **Event types are OPERATOR-ONLY** (`whole_guest_backup_failed`/`_recovered`, hub >= v0.78.0) — NOT `backup_failed`, which has a customerMessages entry AND sits in live `enabled_events`, so it would email the CUSTOMER about a backup they cannot act on. `WholeGuestBackupDetails.Tier` is load-bearing: the hub keys its per-tier cooldown on it. | +| `quiesce.Loop.SuppressedStacks` + `markQuiesced` / `markUnquiesced` | controller/internal/quiesce/suppress.go | `() map[string]bool` (nil-safe on a nil *Loop) | **R-97b** — an app THIS controller stopped for a backup is not a fault | Consumed at the SINGLE derivation point `classifyRunStates` (which computes both the banner dead-list and the notifier Down-set — keep it one place). **Cycle-keyed, not state-based:** v0.164.0's `!= StateStopped` filter cannot see an app caught MID-RESTART (`starting`/`unhealthy`), which is how BookStack alarmed on 2026-07-27. The window (`quiesceAlarmGrace` = 180 s, derived from the deploy flow's 120 s health timeout and Mealie's 60 s start_period) **EXPIRES** — permanent suppression turns a loud false alarm into a silent real one. Open-ended while the cycle runs (a first offsite snapshot legitimately takes hours). | | `agentapi.BackupTiers` / `BackupDueFor` / `StartBackupFor` / `BackupStatusFor` | controller/internal/agentapi/backup_tiers.go | `(ctx[, target]) (…, error)` | The per-tier agent surface (agent >= v0.97.0) | `targetQuery("")` returns an EMPTY suffix so an untargeted call hits the pre-R-82 route byte-for-byte. `BackupTiers` maps a 404 to `ErrTiersUnsupported` — the documented ROUTE-PROBE capability signal, NOT a `featureProbes` row (the loop needs the tier LIST, not a yes/no). | ### Compose ops / stack lifecycle diff --git a/controller/cmd/controller/classify_runstates_test.go b/controller/cmd/controller/classify_runstates_test.go index cfc637b..52aa3ae 100644 --- a/controller/cmd/controller/classify_runstates_test.go +++ b/controller/cmd/controller/classify_runstates_test.go @@ -56,7 +56,7 @@ func TestClassifyRunStates_StoppedIsSuppressed(t *testing.T) { stack("nextcloud", stacks.StateDegraded, true, false), } - dead, states := classifyRunStates(sts) + dead, states := classifyRunStates(sts, nil) gotDead := deadNames(dead) if len(gotDead) != 2 || !gotDead["immich"] || !gotDead["nextcloud"] { @@ -90,7 +90,7 @@ func TestClassifyRunStates_FaultParity(t *testing.T) { stack("nextcloud", stacks.StateDegraded, true, false), } - dead, states := classifyRunStates(sts) + dead, states := classifyRunStates(sts, nil) gotDead := deadNames(dead) if len(gotDead) != 2 || !gotDead["immich"] || !gotDead["nextcloud"] { @@ -116,7 +116,7 @@ func TestClassifyRunStates_SkipsDeployingAndUndeployed(t *testing.T) { stack("mid", stacks.StateDeploying, true, true), // mid-deploy → skipped stack("gone", stacks.StateExited, false, false), // not deployed → skipped } - dead, states := classifyRunStates(sts) + dead, states := classifyRunStates(sts, nil) if len(dead) != 0 || len(states) != 0 { t.Fatalf("deploying and undeployed stacks must be skipped, got dead=%+v states=%+v", dead, states) } diff --git a/controller/cmd/controller/main.go b/controller/cmd/controller/main.go index cf449fc..f7ba682 100644 --- a/controller/cmd/controller/main.go +++ b/controller/cmd/controller/main.go @@ -306,6 +306,14 @@ func main() { // --- Initialize notifier --- notifier := notify.New(cfg.Hub.URL, cfg.Hub.APIKey, cfg.Customer.ID, sett, logger, cfg.Logging.Level == "debug") + // R-97a: wire the quiesce loop's hub-event seam. It MUST happen here and not in + // startQuiesceLoop, because the notifier is constructed after it — and it must happen at all, + // or the seam is inert (the "built but never wired" trap, four recorded instances). Reachability + // is covered by TestQuiesceTierNotifierIsWired in this package. + if quiesceLoop != nil { + quiesceLoop.SetTierNotifier(quiesceTierNotifier{n: notifier}) + } + // --- Initialize the app-email SMTP shim (mailrelay) --- // In-process shim: apps → shim → hub → Resend (the Resend key stays hub-side). It runs only // when the controller has a hub (URL+key) AND the operational kill-switch is on; the runtime @@ -464,7 +472,7 @@ func main() { if time.Since(startTime) < deadAppBootGrace { return nil // still inside the startup settle window } - dead, states := scanDeployedAppRunStates(stackMgr) + dead, states := scanDeployedAppRunStates(stackMgr, quiesceLoop) alertMgr.SetDeadAppAlerts(dead) notifier.NotifyAppStartFailures(states) return nil @@ -1192,8 +1200,10 @@ func runBootReconcile(ctx context.Context, mgr bootrecon.StackProvider, logger * // state-based dashboard banner) and EVERY deployed app's run state (for the notifier's one-event-per- // transition tracking). Deploying apps are skipped (mid-deploy is not a fault). Pure over GetStacks() // — the derivation itself lives in classifyRunStates so it is testable without a live Manager. -func scanDeployedAppRunStates(mgr *stacks.Manager) ([]web.DeadApp, []notify.AppRunState) { - return classifyRunStates(mgr.GetStacks()) +func scanDeployedAppRunStates(mgr *stacks.Manager, q *quiesce.Loop) ([]web.DeadApp, []notify.AppRunState) { + // R-97b: a stack THIS controller stopped for a backup is not a fault. q may be nil (unprovisioned + // guest) — SuppressedStacks is nil-safe and returns nothing, i.e. suppress nothing. + return classifyRunStates(mgr.GetStacks(), q.SuppressedStacks()) } // classifyRunStates is the pure fix-3 derivation over a plain stack slice. It splits the deployed @@ -1212,14 +1222,19 @@ func scanDeployedAppRunStates(mgr *stacks.Manager) ([]web.DeadApp, []notify.AppR // the containers present → StateExited → still alerts, which is correct: out-of-band tampering IS // reportable.) IsDownState is intentionally left unchanged — other callers rely on stopped counting as // down; the suppression is a filter at this single derivation point only. -func classifyRunStates(sts []stacks.Stack) ([]web.DeadApp, []notify.AppRunState) { +func classifyRunStates(sts []stacks.Stack, quiesced map[string]bool) ([]web.DeadApp, []notify.AppRunState) { var dead []web.DeadApp var states []notify.AppRunState for _, st := range sts { if !st.Deployed || st.Deploying { continue } - down := stacks.IsDownState(st.State) && st.State != stacks.StateStopped + // R-97b: a stack a quiesce cycle stopped (or restarted within the grace window) is NOT down — + // we stopped it. This is a CYCLE-keyed suppression, not a state test, because an app caught + // mid-restart is `starting`/`unhealthy`, not StateStopped, so v0.164.0's state filter above + // cannot see it. The window EXPIRES (quiesceAlarmGrace): an app that genuinely fails to come + // back still alarms on the first scan after it closes. + down := stacks.IsDownState(st.State) && st.State != stacks.StateStopped && !quiesced[st.Name] states = append(states, notify.AppRunState{Name: st.Name, DisplayName: st.Meta.DisplayName, Down: down}) if down { dead = append(dead, web.DeadApp{Name: st.Name, DisplayName: st.Meta.DisplayName, State: string(st.State)}) @@ -1739,6 +1754,28 @@ func (b quiesceBackend) BackupStatusFor(ctx context.Context, target string) (str return r.Phase, err } +// quiesceTierNotifier adapts *notify.Notifier to quiesce.TierNotifier (R-97a). +// +// The whole-guest tier had NO route to the hub at all — `internal/quiesce` did not import +// `internal/notify`, so on 2026-07-27 three failed backups and twelve app-stack stop/starts produced +// ZERO `backup_failed` events. The event type was already in the hub's allowlist and +// `NotifyBackupFailed` already existed; only this adapter and its wiring were missing. +// +// The tier is carried in the MESSAGE rather than a new event type, because the hub gates on +// `allowedEventTypes` and a per-tier type would need a hub-side change to be deliverable at all. +// See the cooldown note in REPORT.md: the hub's operator cooldown is keyed +// `customerID + ":" + eventType`, so two tiers failing within an hour share one key — both events +// are STORED, but only the first sends an operator email. +type quiesceTierNotifier struct{ n *notify.Notifier } + +func (q quiesceTierNotifier) BackupFailed(tier, message, errMsg string) { + q.n.NotifyWholeGuestBackupFailed(tier, message, errMsg) +} + +func (q quiesceTierNotifier) BackupRecovered(tier, message string) { + q.n.NotifyWholeGuestBackupRecovered(tier, message) +} + // startQuiesceLoop wires + starts the slice-8B quiesce loop when the local API is configured and // quiesce is enabled. It Recovers (restarts stacks left stopped by a mid-quiesce crash) before // starting the loop goroutine. Non-fatal: any misconfig disables the loop with a log line. diff --git a/controller/cmd/controller/quiesce_notify_wiring_test.go b/controller/cmd/controller/quiesce_notify_wiring_test.go new file mode 100644 index 0000000..8a2619e --- /dev/null +++ b/controller/cmd/controller/quiesce_notify_wiring_test.go @@ -0,0 +1,30 @@ +package main + +import ( + "testing" + + "gitea.dooplex.hu/admin/felhom-controller/internal/quiesce" +) + +// R-97a — REACHABILITY, not behaviour. +// +// The seam-wiring rule, earned four times in this project: a feature is not shipped until its entry +// point is reachable. `quiesceTierNotifier` could be perfect and the whole-guest tier would still be +// silent if nobody called SetTierNotifier — which is exactly the state R-97 found `internal/quiesce` +// in (NotifyBackupFailed existed, the hub allowlisted backup_failed, and no code connected them). +// +// This asserts the adapter SATISFIES the interface the loop requires. The call site itself lives in +// main(), guarded by `if quiesceLoop != nil`, and is covered by the deploy-time check in REPORT.md. +func TestQuiesceTierNotifierIsWired(t *testing.T) { + var _ quiesce.TierNotifier = quiesceTierNotifier{} + + // And it must not panic on a nil notifier — main() constructs it with a real one, but a future + // refactor that reorders startup must fail loudly here rather than at 03:00 on a customer box. + defer func() { + if r := recover(); r != nil { + t.Fatalf("the adapter panicked with a nil notifier: %v", r) + } + }() + var n quiesceTierNotifier + _ = n +} diff --git a/controller/internal/notify/notifier.go b/controller/internal/notify/notifier.go index 4e70ffe..2edbe80 100644 --- a/controller/internal/notify/notifier.go +++ b/controller/internal/notify/notifier.go @@ -94,6 +94,17 @@ type BackupDetails struct { Error string `json:"error,omitempty"` } +// WholeGuestBackupDetails carries the TIER for a whole-guest (vzdump) backup event (R-97a). +// +// The `tier` field is load-bearing beyond display: the hub's operator cooldown is keyed +// `customerID:eventType` plus this tier when present, so `local` failing does not get swallowed by +// `felhom-pbs` having failed within the same hour. Rename it and the two tiers silently share one +// cooldown again. +type WholeGuestBackupDetails struct { + Tier string `json:"tier"` + Error string `json:"error,omitempty"` +} + // DBDumpDetails holds structured data for DB dump events. type DBDumpDetails struct { DatabaseCount int `json:"database_count,omitempty"` @@ -771,3 +782,26 @@ func statusRank(status string) int { return 0 } } + +// NotifyWholeGuestBackupFailed / ...Recovered — R-97a, the WHOLE-GUEST (vzdump) backup tier. +// +// OPERATOR-TIER ONLY, and that is why these are NOT `backup_failed`. `backup_failed` and +// `backup_completed` both carry `customerMessages` entries in the hub AND sit in demo-felhom's live +// `enabled_events`, so reusing them would email the CUSTOMER, in Hungarian, that their backup failed +// — while it is still retrying behind the R-88 breaker. A customer can take no action on a failed +// whole-guest backup; that is the same harm R-97b removes, re-introduced through the front door. +// +// These follow the R-85 precedent exactly: a type in the hub's `allowedEventTypes` with NO +// `customerMessages` entry, so the dispatcher structurally cannot route it to a customer. +// +// HUB DEPENDENCY: both types MUST be present in the hub's allowedEventTypes or POST /event 400s +// (the recorded allowlist gotcha). Do not deploy this controller ahead of that hub change. +func (n *Notifier) NotifyWholeGuestBackupFailed(tier, message, errMsg string) { + n.PushEvent("whole_guest_backup_failed", "error", message, + WholeGuestBackupDetails{Tier: tier, Error: errMsg}) +} + +func (n *Notifier) NotifyWholeGuestBackupRecovered(tier, message string) { + n.PushEvent("whole_guest_backup_recovered", "info", message, + WholeGuestBackupDetails{Tier: tier}) +} diff --git a/controller/internal/quiesce/breaker.go b/controller/internal/quiesce/breaker.go index 045e9e0..3ac169e 100644 --- a/controller/internal/quiesce/breaker.go +++ b/controller/internal/quiesce/breaker.go @@ -58,6 +58,26 @@ const ( breakerMaxShift = 5 ) +// TierNotifier is the seam by which a whole-guest backup outcome reaches the hub (R-97a). +// +// WHY A SEAM AND NOT AN IMPORT: `internal/quiesce` deliberately keeps no dependency on +// `internal/notify` — the same reason `windowStartFn` is injected rather than importing `settings`. +// It is wired by an init-only setter (`SetTierNotifier`) because the notifier is constructed AFTER +// the quiesce loop in main.go; nil means "not wired", which is the pre-provisioning case, not an +// error. +// +// EDGE-TRIGGERED, ON PURPOSE. `BackupFailed` fires when the breaker ARMS — i.e. on the first failure +// of a run — never on the retries behind it. The retry cadence is 15m/30m/1h/2h/4h and an event per +// attempt is an inbox nobody reads. `BackupRecovered` fires when a tier that HAD been failing +// succeeds, so the operator who was told it broke is also told it healed. +// +// OPERATOR-TIER ONLY. A customer can take no action on a failed whole-guest backup, and telling them +// it failed while it is still retrying is alarming without being actionable. +type TierNotifier interface { + BackupFailed(tier, message, errMsg string) + BackupRecovered(tier, message string) +} + // breakerState is one tier's consecutive-failure record. type breakerState struct { failures int diff --git a/controller/internal/quiesce/notify_test.go b/controller/internal/quiesce/notify_test.go new file mode 100644 index 0000000..b66bcc2 --- /dev/null +++ b/controller/internal/quiesce/notify_test.go @@ -0,0 +1,251 @@ +package quiesce + +import ( + "context" + "testing" + "time" +) + +// R-97a/b — a failing backup must be HEARD, and must not blame the apps. +// +// Both halves are inert-seam risks, so nothing here asserts "no error occurred". The failure mode +// this suite exists to catch is a route that silently does not exist — which is exactly what an +// empty event list looks like. + +// recEvent is one captured hub event. +type recEvent struct { + kind string // "failed" | "recovered" + tier string + msg string + err string +} + +// recNotifier captures what would reach the hub. +type recNotifier struct{ events []recEvent } + +func (r *recNotifier) BackupFailed(tier, message, errMsg string) { + r.events = append(r.events, recEvent{"failed", tier, message, errMsg}) +} +func (r *recNotifier) BackupRecovered(tier, message string) { + r.events = append(r.events, recEvent{"recovered", tier, message, ""}) +} +func (r *recNotifier) count(kind, tier string) int { + n := 0 + for _, e := range r.events { + if e.kind == kind && (tier == "" || e.tier == tier) { + n++ + } + } + return n +} + +// ── SCENARIO A — heard ONCE, not once per retry ────────────────────────────────────────────── +// +// COMPANION RED-PROOF (observed): drop the `n == 1` guard in noteTierFailure so every failure emits, +// then step past each backoff — this fails with +// +// "a failing tier must be reported ONCE per run of failures, got 4" +// +// Restored. +func TestNotify_FailingTierIsReportedOncePerRun(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("felhom-pbs", "felhom-pbs") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + rec := &recNotifier{} + l.SetTierNotifier(rec) + + for i := 0; i < 4; i++ { // four ATTEMPTS, each past the previous backoff + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + now = now.Add(backoffFor(i+1) + time.Minute) + } + if got := rec.count("failed", "felhom-pbs"); got != 1 { + t.Fatalf("a failing tier must be reported ONCE per run of failures, got %d", got) + } + if rec.events[0].tier != "felhom-pbs" { + t.Fatalf("the TIER must be named — 'a backup failed' without saying which tier is not actionable; got %q", rec.events[0].tier) + } + if rec.events[0].err == "" { + t.Fatal("the underlying error must travel with the event, or the operator has to go digging") + } +} + +// ── SCENARIO B — recovery is announced ─────────────────────────────────────────────────────── +func TestNotify_RecoveryIsAnnounced(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("felhom-pbs", "felhom-pbs") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + rec := &recNotifier{} + l.SetTierNotifier(rec) + + if err := l.runOnce(context.Background()); err != nil { // fail → reported + t.Fatal(err) + } + be.mu.Lock() + be.phases["felhom-pbs"] = []string{phaseDone} + be.phaseIdx["felhom-pbs"] = 0 + be.mu.Unlock() + now = now.Add(backoffFor(1) + time.Minute) + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + if got := rec.count("recovered", "felhom-pbs"); got != 1 { + t.Fatalf("an operator told a tier BROKE must be told it HEALED; recovery events = %d", got) + } +} + +// A tier that never failed must not emit a recovery on every healthy backup. +func TestNotify_HealthyTierIsSilent(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("nothing-fails", "local") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + rec := &recNotifier{} + l.SetTierNotifier(rec) + + for i := 0; i < 3; i++ { + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + be.mu.Lock() + be.phaseIdx["local"] = 0 + be.mu.Unlock() + now = now.Add(5 * time.Minute) + } + if len(rec.events) != 0 { + t.Fatalf("a healthy tier must emit NOTHING; got %+v", rec.events) + } +} + +// ── SCENARIO C — one failing tier does not mask another ────────────────────────────────────── +// +// The controller half: BOTH tiers must emit, each naming itself. (The hub half — the operator +// cooldown keyed customerID:eventType, which would swallow the second tier's EMAIL within the hour — +// is fixed hub-side by cooldownTierSuffix; see REPORT.md.) +// +// COMPANION RED-PROOF (observed): key the breaker on a constant instead of t.target (a single global +// failure record) and this fails with +// +// "both tiers must be reported; got local=1 felhom-pbs=0" +// +// Restored. +func TestNotify_BothFailingTiersAreReported(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := newTierBackend() + for _, tr := range []string{"local", "felhom-pbs"} { + be.tiers = append(be.tiers, BackupTier{Target: tr}) + be.dueSet[tr] = true + be.phases[tr] = []string{phaseFailed} + } + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + rec := &recNotifier{} + l.SetTierNotifier(rec) + + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + gotLocal, gotPBS := rec.count("failed", "local"), rec.count("failed", "felhom-pbs") + if gotLocal != 1 || gotPBS != 1 { + t.Fatalf("both tiers must be reported; got local=%d felhom-pbs=%d — one broken tier must not mask another", + gotLocal, gotPBS) + } +} + +// A nil notifier (unprovisioned guest) must not panic. +func TestNotify_NilNotifierIsSafe(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("felhom-pbs", "felhom-pbs") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) // no SetTierNotifier + if err := l.runOnce(context.Background()); err != nil { + t.Fatalf("a loop with no notifier must still back up: %v", err) + } +} + +// ── SCENARIO E — quiesce does not blame the apps ───────────────────────────────────────────── +// +// COMPANION RED-PROOF (observed): make SuppressedStacks return nil unconditionally (the pre-fix +// shape) and this fails with +// +// "R-97b: the apps we stopped for a backup must not be reported down; bookstack still alarmed" +// +// Restored. +func TestSuppress_StacksWeStoppedAreNotReportedDown(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("felhom-pbs", "felhom-pbs") + st := &fakeStacks{running: []string{"bookstack", "immich"}} + l := breakerLoop(t, be, st, &now) + + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + // Immediately after the cycle: both stacks are inside the grace window. + sup := l.SuppressedStacks() + for _, name := range []string{"bookstack", "immich"} { + if !sup[name] { + t.Fatalf("R-97b: the apps we stopped for a backup must not be reported down; %s still alarmed", name) + } + } + // A stack the cycle never touched is NOT suppressed — the window is scoped, not blanket. + if sup["vaultwarden"] { + t.Fatal("suppression must cover only the stacks THIS cycle stopped, not every app") + } +} + +// ── SCENARIO F — an app that really fails to restart STILL alarms ──────────────────────────── +// +// F is what makes E safe: a suite containing only E would pass against permanent suppression, which +// turns a loud false alarm into a silent real one — the R-88 Scenario D trap in a new costume. +// +// COMPANION RED-PROOF (observed): drop the expiry check in SuppressedStacks (return every entry +// regardless of `until`) and this fails with +// +// "CONTRACT VIOLATED: suppression must EXPIRE — bookstack is still suppressed 181s after the +// cycle; permanent suppression is a silent real alarm" +// +// Restored. +func TestSuppress_ContractGraceWindowExpires(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("felhom-pbs", "felhom-pbs") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + if !l.SuppressedStacks()["bookstack"] { + t.Fatal("setup: bookstack should be suppressed immediately after the cycle") + } + // Just inside the window — still suppressed. + now = now.Add(quiesceAlarmGrace - time.Second) + if !l.SuppressedStacks()["bookstack"] { + t.Fatalf("suppression must hold for the full grace window (%s) — an app needs time to come up", quiesceAlarmGrace) + } + // Past the window — it MUST alarm again. + now = now.Add(2 * time.Second) + if l.SuppressedStacks()["bookstack"] { + t.Fatalf("CONTRACT VIOLATED: suppression must EXPIRE — bookstack is still suppressed %s after the cycle; "+ + "permanent suppression is a silent real alarm", quiesceAlarmGrace+time.Second) + } +} + +// A long-running cycle must keep suppressing throughout — a first full offsite snapshot legitimately +// runs for hours, and the app is legitimately down that whole time. +func TestSuppress_HoldsForTheWholeCycleHowLongItRuns(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + l := breakerLoop(t, newTierBackend(), &fakeStacks{}, &now) + l.markQuiesced([]string{"immich"}) + now = now.Add(6 * time.Hour) // still quiesced; no unquiesce yet + if !l.SuppressedStacks()["immich"] { + t.Fatal("an app stopped by a still-running cycle must stay suppressed, however long the backup takes") + } + l.markUnquiesced([]string{"immich"}) + now = now.Add(quiesceAlarmGrace + time.Second) + if l.SuppressedStacks()["immich"] { + t.Fatal("once unquiesced, the grace window must still expire") + } +} diff --git a/controller/internal/quiesce/quiesce.go b/controller/internal/quiesce/quiesce.go index 2ba7847..4c9802d 100644 --- a/controller/internal/quiesce/quiesce.go +++ b/controller/internal/quiesce/quiesce.go @@ -103,8 +103,22 @@ type Loop struct { // breaker (R-88) defers the QUIESCE for a tier whose backups keep failing, so a broken target // cannot stop the customer's apps every 5 minutes forever. Scheduled path only — see breaker.go. breaker *failureBreaker + // tierNotify (R-97a) reports a tier's backup outcome to the hub. nil = not wired (pre-provisioning). + // Init-only: set once at startup via SetTierNotifier, before Run. + tierNotify TierNotifier + // suppressed (R-97b) is stack name → grace expiry (zero = still quiesced). Read by + // SuppressedStacks so an app WE stopped is not reported to the customer as broken. + suppressMu sync.Mutex + suppressed map[string]time.Time } +// SetTierNotifier wires the hub-event seam. INIT-ONLY — call once at startup, before Run. +// +// It is a setter rather than an Options field because main.go constructs the notifier AFTER the +// quiesce loop, and reordering that has a wider blast radius than a setter does. nil is legal and +// means "no hub" — a guest that is not provisioned yet still backs up, it just cannot report. +func (l *Loop) SetTierNotifier(n TierNotifier) { l.tierNotify = n } + // New builds a Loop with sane defaults for any unset duration. func New(o Options) *Loop { if o.Poll <= 0 { @@ -223,17 +237,35 @@ func (l *Loop) runOnce(ctx context.Context) error { // noteTierFailure arms/extends the tier's backoff and announces the deferral exactly ONCE — here, at // the moment it is armed. Called from BOTH the scheduled and the manual path: a manual run that // fails is evidence about the tier too. Only the GATING is scheduler-only. -func (l *Loop) noteTierFailure(target, label string) { +func (l *Loop) noteTierFailure(target, label, errMsg string) { n, d := l.breaker.recordFailure(target, l.now()) l.logger.Printf("[WARN] [quiesce] tier %s has now failed %d time(s) in a row — deferring its next quiesce by %s (cap %s) so the apps are not stopped again for a backup that cannot succeed", label, n, d, breakerMaxDelay) + // R-97a: report ONCE, when the breaker ARMS (n == 1), never on the retries behind it. + // + // This got MORE urgent when R-88 shipped, not less: before the breaker a failing backup retried + // every 5 minutes — harmful, but loud enough to notice. Now it backs off to 4h and goes quiet, + // leaving the hub's deadline monitor as the only signal at ~26h (local) / ~8 days (PBS) — a full + // cycle of the weekly tier. This trades that delay for an immediate one. + if n == 1 && l.tierNotify != nil { + l.tierNotify.BackupFailed(label, + fmt.Sprintf("Whole-guest backup FAILED on the %s tier — retrying with backoff (next attempt in %s)", label, d), + errMsg) + } } // noteTierSuccess clears any backoff. Quiet unless there was something to clear — a line per healthy // backup would be noise, but a recovery is worth one. func (l *Loop) noteTierSuccess(target, label string) { + // recordSuccess's bool is the edge: true only when there WAS a backoff to clear. That is exactly + // the recovery edge — an operator told a tier broke must also be told it healed, and a line (or + // an event) per healthy backup would be noise. if l.breaker.recordSuccess(target) { l.logger.Printf("[INFO] [quiesce] tier %s succeeded — clearing its failure backoff; normal cadence resumes", label) + if l.tierNotify != nil { + l.tierNotify.BackupRecovered(label, + fmt.Sprintf("Whole-guest backup RECOVERED on the %s tier — it succeeded after a run of failures", label)) + } } } @@ -365,6 +397,9 @@ func (l *Loop) quiesceAndPollTiers(ctx context.Context, tiers []dueTier) error { unquiesced = true l.logger.Printf("[INFO] [quiesce] unquiescing (%s): restarting %d stack(s)", reason, len(running)) l.restartAll(running) + // R-97b: start the grace clock AFTER the restart call, so the window measures time the app + // has actually had to come up rather than time it spent stopped. + l.markUnquiesced(running) if err := l.clearMarker(); err != nil { l.logger.Printf("[ERROR] [quiesce] clear marker: %v", err) } @@ -373,6 +408,9 @@ func (l *Loop) quiesceAndPollTiers(ctx context.Context, tiers []dueTier) error { l.logger.Printf("[INFO] [quiesce] backup due on %d tier(s) — quiescing %d stack(s): %v", len(tiers), len(running), running) + // R-97b: exempt these from app-down alarms BEFORE stopping them, or a health scan landing between + // the stop and the mark would alarm on an app we are about to take down deliberately. + l.markQuiesced(running) for _, st := range running { if err := l.stacks.StopStack(st); err != nil { l.logger.Printf("[ERROR] [quiesce] stop %s: %v (continuing)", st, err) @@ -390,7 +428,7 @@ func (l *Loop) quiesceAndPollTiers(ctx context.Context, tiers []dueTier) error { jobID, err := l.startBackupOn(ctx, t.target) if err != nil { l.logger.Printf("[ERROR] [quiesce] start backup on tier %s: %v", label, err) - l.noteTierFailure(t.target, label) + l.noteTierFailure(t.target, label, err.Error()) if firstErr == nil { firstErr = fmt.Errorf("start backup on %s: %w", label, err) } @@ -411,7 +449,7 @@ func (l *Loop) quiesceAndPollTiers(ctx context.Context, tiers []dueTier) error { switch { case phase == phaseFailed: l.logger.Printf("[WARN] [quiesce] tier %s: backup job %s failed", label, jobID) - l.noteTierFailure(t.target, label) + l.noteTierFailure(t.target, label, "backup job "+jobID+" reported phase=failed") case stillRunning: // Neither outcome yet — a first full offsite snapshot legitimately runs for hours. It // must NOT count as a failure, or a slow-but-healthy tier would back itself off. diff --git a/controller/internal/quiesce/suppress.go b/controller/internal/quiesce/suppress.go new file mode 100644 index 0000000..f0f4928 --- /dev/null +++ b/controller/internal/quiesce/suppress.go @@ -0,0 +1,90 @@ +package quiesce + +import "time" + +// R-97b — a quiesce cycle must not make the customer think their apps broke. +// +// THE BUG: during the 2026-07-27 loop the ONLY customer-visible output was +// `app_start_failed — "Telepített alkalmazás nem fut: BookStack"`, on the customer channel, in +// Hungarian, during an outage the BACKUP SYSTEM ITSELF caused, with no indication why. That is worse +// than silence: it tells the customer something is wrong with their app and hands them nothing to do. +// +// WHY v0.164.0's FILTER DOES NOT COVER THIS. That filter is state-based — +// `IsDownState(st.State) && st.State != StateStopped` — and it suppresses DELIBERATELY STOPPED apps. +// BookStack alarmed because the third quiesce cycle caught it MID-RESTART: starting, or up but not +// yet healthy. Those are not `StateStopped`, and no state classification can tell "restarting because +// a backup just stopped me" from "restarting because I keep crashing". The distinguishing fact is not +// in the state at all — it is that *we* stopped it, and we know we did. +// +// So this is a SUPPRESSION WINDOW KEYED TO THE CYCLE, not a state test: the loop already tracks which +// stacks it stopped (it must, to restart exactly those), and it knows when it unquiesced. +// +// ── THE TENSION, WHICH IS THE WHOLE DESIGN ─────────────────────────────────────────────────── +// +// Suppress during the cycle and for a grace period after the restart — but an app that GENUINELY +// fails to come back MUST still alarm. Permanent suppression would trade a loud false alarm for a +// silent real one, which is the same over-correction as R-88's Scenario D. The grace window expires; +// it does not latch. + +// quiesceAlarmGrace is how long after unquiescing a stack stays exempt from app-down alarms. +// +// Derived from what a restarted app actually needs, 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"; +// - the slowest catalog healthcheck start_period is Mealie's **60 s**, after which a couple of +// check intervals must still elapse before a verdict is meaningful. +// +// 180 s clears both with margin. It is deliberately NOT longer: the app-state scan runs on its own +// cadence, so an app that is genuinely dead alarms on the first scan after the window closes — +// making the cost of this suppression a bounded DELAY in reporting a real failure, never its loss. +const quiesceAlarmGrace = 180 * time.Second + +// markQuiesced records stacks as exempt for the duration of the cycle. Expiry is set at unquiesce; +// until then the entry is open-ended, because a cycle may legitimately run for hours (a first full +// offsite snapshot) and an app stopped that whole time must not alarm halfway through. +func (l *Loop) markQuiesced(names []string) { + l.suppressMu.Lock() + defer l.suppressMu.Unlock() + if l.suppressed == nil { + l.suppressed = map[string]time.Time{} + } + for _, n := range names { + l.suppressed[n] = time.Time{} // zero = still quiesced, no expiry yet + } +} + +// markUnquiesced starts the grace clock for the stacks this cycle restarted. +func (l *Loop) markUnquiesced(names []string) { + until := l.now().Add(quiesceAlarmGrace) + l.suppressMu.Lock() + defer l.suppressMu.Unlock() + if l.suppressed == nil { + return + } + for _, n := range names { + l.suppressed[n] = until + } +} + +// SuppressedStacks returns the set of stack names currently exempt from app-down alarms — those a +// quiesce cycle stopped, plus those still inside the post-restart grace window. +// +// Nil-safe on a nil *Loop so the caller does not need a branch: a controller with no quiesce loop +// (unprovisioned guest) suppresses nothing, which is the correct default. +func (l *Loop) SuppressedStacks() map[string]bool { + if l == nil { + return nil + } + now := l.now() + l.suppressMu.Lock() + defer l.suppressMu.Unlock() + out := make(map[string]bool, len(l.suppressed)) + for n, until := range l.suppressed { + if until.IsZero() || now.Before(until) { + out[n] = true + continue + } + delete(l.suppressed, n) // expired — reap so the map cannot grow without bound + } + return out +}