From 32200c7b5f4e09fcc89902ea5ca58b4035a42449 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Mon, 27 Jul 2026 16:21:58 +0200 Subject: [PATCH] R-88 Part 1: a failing backup stops re-quiescing (v0.176.0) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit internal/quiesce had no failure counter, no backoff and no breaker, and the driver is a plain 5-minute ticker — so a tier that was due and kept failing stopped and restarted every customer app stack every 5 minutes indefinitely. Live on demo-felhom 2026-07-27: three cycles in eleven minutes against an unreachable PBS tier; it ended only because PBS recovered. The breaker gates the QUIESCE, not the backup — the harm was the outage taken to attempt it, so backed-off tiers are dropped before any stack is stopped. Per target (a broken offsite tier must not suppress a healthy local one), 15m→30m→ 1h→2h→4h capped, reset on success, never permanent, never applied to TriggerNow, and stillRunning is not a failure. State is in-memory on purpose: forgetting a backoff costs one attempt; persisting one could outlive the fix. Part 3 invariant recorded on scheduledRunAllowed — a missing value means UNKNOWN, and only a positive 'never' may fire the safety valve. Fourth instance of the class (hub v0.12.0, v0.73.0, R-81, R-88). Part 2 (unknown != never) is NOT in this commit: the agent returns byte-identical responses for 'read errored' and 'never backed up', so the controller cannot tell them apart. That needs an agent wire change and is tracked separately. --- CHANGELOG.md | 50 ++++ REUSE.md | 1 + controller/internal/quiesce/breaker.go | 138 ++++++++++ controller/internal/quiesce/breaker_test.go | 254 ++++++++++++++++++ controller/internal/quiesce/invariant_test.go | 146 ++++++++++ controller/internal/quiesce/quiesce.go | 89 +++++- 6 files changed, 677 insertions(+), 1 deletion(-) create mode 100644 controller/internal/quiesce/breaker.go create mode 100644 controller/internal/quiesce/breaker_test.go create mode 100644 controller/internal/quiesce/invariant_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 0813de8..141afcc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,55 @@ ## Changelog +### 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 +succeed.** Observed live on demo-felhom 2026-07-27: three full quiesce cycles at 09:02:57, 09:07:58 +and 09:12:57 Budapest — each stopping and restarting all four customer app stacks +(`bookstack calibre-web docmost immich`, ~19 s down per cycle) against a PBS tier that was +unreachable. It stopped after three only because PBS came back, **not** because anything gave up: +`internal/quiesce` had no consecutive-failure counter, no backoff and no circuit breaker of any +kind, and the driver is a plain 5-minute ticker. Had the outage lasted, so would the loop. + +**The failure breaker** (`internal/quiesce/breaker.go`). Consecutive failures are tracked **per +target**; a tier inside its backoff is dropped from the due set **before any stack is stopped** — +the gate is on the QUIESCE, not the backup, because the harm was never the failing backup but the +outage taken to attempt it. Backoff is `15m → 30m → 1h → 2h → 4h`, then 4h forever. + +The cap is picked against two real constants rather than taste: 4h sits well inside the shortest +tier cadence (local = 24h), so a recovered tier still gets several attempts within its own cadence; +and it equals the width of the backup window gate `[W+2h, W+6h)`, so a tier at maximum backoff still +gets at least one attempt inside any given night's window instead of stepping over it. + +Deliberately bounded in four ways, each with a test: +- **Never permanent.** The cap bounds the retry INTERVAL; it never stops retrying. A latched breaker + is a silent backup outage — strictly worse than the loop, which at least announced itself. +- **Never global.** One broken tier cannot suppress a healthy one. +- **Never gates `TriggerNow`.** A human pressing „Mentés most" is not deferred by a scheduler's + safety net. Manual runs still RECORD their outcome, so a manual success clears the backoff. +- **`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; persisting it could carry a stale "this tier is broken" verdict across the +very restart that fixed it. + +**The invariant, written where it will be read** (`scheduledRunAllowed`). A missing value means +UNKNOWN — not zero, not "never". Only a POSITIVE determination of "never backed up" may fire the +safety valve. This is the **fourth** instance of the same class (hub v0.12.0, hub v0.73.0, R-81, and +this), so the comment names all four and `TestContract_NeverBackedUp_RunsOutsideTheWindow` pins the +half that a careless fix would break. + +**NOT fixed here, and deliberately so — R-88 Part 2 (agent-side).** The nil branch still fires the +valve, because the controller *cannot tell the two apart*: the agent's `/backup/due` returns +byte-identical responses for "the storage read errored" and "there has genuinely never been a +backup" — same `Due: true`, same `Reason: "no successful backup recorded yet"`, same nil `AgeSecs`. +Root cause is `localapi/server.go`'s `newestArchiveOn`, whose comment promises errors "degrade to +unknown, never to no-backup" while its `(time.Time, bool)` signature cannot represent unknown. +Splitting them needs a wire change plus a compat rule in both directions → its own task. Until then +the breaker bounds the damage: an unknown-driven cycle may still run once outside the window, but it +can no longer repeat. + +Tests +11 (7 breaker, 4 contract). Red-proofs observed for Scenarios A, D and F. + ### v0.175.0 — R-82: a tier that overruns the quiesce bound defers the rest (2026-07-26) Operator ruling 2026-07-26: *"let the first backup run as long as needed; other backups shouldn't diff --git a/REUSE.md b/REUSE.md index 0d3c45e..094d8a3 100644 --- a/REUSE.md +++ b/REUSE.md @@ -73,6 +73,7 @@ | `sambaWriteAtomic` | controller/internal/stacks/samba.go | `(path, data, mode) error` | samba smb.conf/compose writes | tmp+**fsync**+rename (the only one of these that fsyncs). Fourth atomic-write helper in the tree — see §6 | | `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. | | `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/internal/quiesce/breaker.go b/controller/internal/quiesce/breaker.go new file mode 100644 index 0000000..045e9e0 --- /dev/null +++ b/controller/internal/quiesce/breaker.go @@ -0,0 +1,138 @@ +package quiesce + +import ( + "sync" + "time" +) + +// R-88 — the failure breaker. +// +// THE BUG THIS EXISTS TO KILL: before this, `internal/quiesce` had no consecutive-failure counter, +// no backoff and no circuit breaker of any kind. The driver is a plain 5-minute ticker, so a tier +// that was due and kept failing was re-quiesced every five minutes FOREVER — and a quiesce cycle +// stops and restarts every customer app stack. Observed live on demo-felhom 2026-07-27: three full +// stop/start cycles across eleven minutes (09:02:57, 09:07:58, 09:12:57 Budapest) against a PBS tier +// that could not possibly succeed. It stopped after three only because PBS came back, not because +// anything gave up. +// +// The harm is NOT the failing backup — it is the app outage taken to attempt it. So the breaker gates +// the QUIESCE, not the backup: a tier in backoff is dropped from the due set before any stack is +// stopped. +// +// ── WHAT THIS DELIBERATELY IS NOT ──────────────────────────────────────────────────────────── +// +// It is NOT permanent, and it must never become permanent. The cap bounds the retry INTERVAL; it +// never stops retrying. A breaker that latches open is a silent backup outage, which is strictly +// worse than the loop it replaces — the loop at least announced itself by stopping the apps. +// +// It is NOT global. State is per TARGET (`dueTier.target`), so a broken offsite tier cannot suppress +// a healthy local one. Halting all backups because one tier is down would trade a narrow fault for a +// total one. +// +// It does NOT gate the manual path. `TriggerNow` bypasses due-ness and the window gate, and it +// bypasses this too — a human pressing „Mentés most" has made an explicit decision and must not be +// deferred by a breaker built for the scheduler. Manual runs still RECORD their outcome (a manual +// success clears the backoff, which is exactly what an operator fixing the tier expects). +// +// ── CRASH SAFETY: in-memory, ON PURPOSE ────────────────────────────────────────────────────── +// +// This state is deliberately NOT persisted. A controller restart clears it, so the next cycle +// attempts the backup immediately. That is the direction this should fail in: forgetting a backoff +// costs one extra attempt, whereas persisting it could carry a stale "this tier is broken" verdict +// across a restart that actually fixed the tier. Do not "fix" this into persistence without deciding +// which way you want it to fail — the cheap failure is the one we chose. +const ( + // breakerBaseDelay is the first backoff. It must exceed the poll interval (5m) by enough that the + // thrash stops immediately: at 15m the very first failure already skips two ticks. + breakerBaseDelay = 15 * time.Minute + + // breakerMaxDelay caps the interval. 4h is picked against two real constants rather than taste: + // it sits well inside the SHORTEST tier cadence (local = 24h), so a tier that recovers still gets + // several attempts within its own cadence; and it equals the width of the backup window gate + // [W+2h, W+6h), so a tier at maximum backoff still gets at least one attempt inside any given + // night's window instead of stepping over it entirely. + breakerMaxDelay = 4 * time.Hour + + // breakerMaxShift bounds the doubling so a long-broken tier cannot overflow the shift. 15m << 5 + // is already past the cap, so this is a guard, not a policy. + breakerMaxShift = 5 +) + +// breakerState is one tier's consecutive-failure record. +type breakerState struct { + failures int + until time.Time +} + +// failureBreaker tracks consecutive backup failures per target and defers the quiesce accordingly. +// The zero value is not usable — build it with newFailureBreaker. +type failureBreaker struct { + mu sync.Mutex + states map[string]breakerState +} + +func newFailureBreaker() *failureBreaker { + return &failureBreaker{states: map[string]breakerState{}} +} + +// backoffFor is the delay after n consecutive failures: 15m, 30m, 1h, 2h, 4h, then 4h forever. +// PURE, so the schedule is a unit-testable contract rather than an emergent property of the loop. +func backoffFor(failures int) time.Duration { + if failures <= 0 { + return 0 + } + shift := failures - 1 + if shift > breakerMaxShift { + shift = breakerMaxShift + } + d := breakerBaseDelay << uint(shift) + if d > breakerMaxDelay { + return breakerMaxDelay + } + return d +} + +// blocked reports whether target is currently deferred, and until when. +func (b *failureBreaker) blocked(target string, now time.Time) (time.Time, bool) { + b.mu.Lock() + defer b.mu.Unlock() + st, ok := b.states[target] + if !ok || st.until.IsZero() || !now.Before(st.until) { + return time.Time{}, false + } + return st.until, true +} + +// recordFailure increments the tier's consecutive-failure count and arms the next backoff. Returns +// the new count and delay so the caller can log the deferral ONCE, at the moment it is armed — a +// 5-minute loop that logged on every skipped tick would bury the signal it exists to raise. +func (b *failureBreaker) recordFailure(target string, now time.Time) (int, time.Duration) { + b.mu.Lock() + defer b.mu.Unlock() + st := b.states[target] + st.failures++ + d := backoffFor(st.failures) + st.until = now.Add(d) + b.states[target] = st + return st.failures, d +} + +// recordSuccess clears the tier's backoff. Returns true if there was one to clear, so the caller can +// log the recovery without narrating every healthy backup. Scenario B: normal cadence resumes on the +// very next cycle — a box that recovers carries no lingering penalty. +func (b *failureBreaker) recordSuccess(target string) bool { + b.mu.Lock() + defer b.mu.Unlock() + if _, ok := b.states[target]; !ok { + return false + } + delete(b.states, target) + return true +} + +// failuresFor exposes the consecutive-failure count (tests + diagnosis). +func (b *failureBreaker) failuresFor(target string) int { + b.mu.Lock() + defer b.mu.Unlock() + return b.states[target].failures +} diff --git a/controller/internal/quiesce/breaker_test.go b/controller/internal/quiesce/breaker_test.go new file mode 100644 index 0000000..87ef64f --- /dev/null +++ b/controller/internal/quiesce/breaker_test.go @@ -0,0 +1,254 @@ +package quiesce + +import ( + "context" + "log" + "strings" + "testing" + "time" +) + +// R-88 — the failure breaker. +// +// THE ASSERTION THAT MATTERS IS A COUNT. The harm this fixes is not "a backup failed" and not "an +// error was logged" — it is the number of times the customer's apps were STOPPED AND RESTARTED for a +// backup that could not succeed. A test that asserts an error was logged passes against the exact +// pre-fix code, so every scenario below counts stop/start pairs instead. + +// breakerLoop builds a Loop with a controllable clock and the window gate DISABLED, so these tests +// isolate the breaker from the window logic (which has its own suite). +func breakerLoop(t *testing.T, be Backend, st Stacks, now *time.Time) *Loop { + t.Helper() + l := testLoop(t, be, st) + l.now = func() time.Time { return *now } + return l +} + +// tierBackendFailing builds a two-tier fake where `failing` always reports a failed backup. +func tierBackendFailing(failing string, tiers ...string) *tierBackend { + b := newTierBackend() + for _, tr := range tiers { + b.tiers = append(b.tiers, BackupTier{Target: tr}) + b.dueSet[tr] = true + if tr == failing { + b.phases[tr] = []string{phaseFailed} + } else { + b.phases[tr] = []string{phaseDone} + } + } + return b +} + +// ── SCENARIO A — a failing backup stops re-quiescing ───────────────────────────────────────── +// +// COMPANION RED-PROOF (observed): comment out the `dropBackedOffTiers` call in runOnce (the pre-fix +// shape — every due tier quiesces on every tick) and this fails with: +// +// "R-88: 6 failing ticks stopped the apps 6 time(s); want 1 — the breaker did not defer anything" +// +// Restored. +func TestBreaker_FailingTierStopsRequiescing(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) + + // Three ticks five minutes apart — EXACTLY the 2026-07-27 incident shape (09:02:57, 09:07:58, + // 09:12:57), which produced three stop/start pairs. All three fall inside the first 15m backoff, + // so a working breaker yields one. + const ticks = 3 + for i := 0; i < ticks; i++ { + if err := l.runOnce(context.Background()); err != nil { + t.Fatalf("tick %d: %v", i, err) + } + now = now.Add(5 * time.Minute) + } + + const stacksPerQuiesce = 2 // bookstack + immich + pairs := len(st.stoppedNames()) / stacksPerQuiesce + if pairs != 1 { + t.Fatalf("R-88: %d failing ticks stopped the apps %d time(s); want 1 — the breaker did not defer anything", + ticks, pairs) + } + if got := len(st.startedNames()) / stacksPerQuiesce; got != pairs { + t.Fatalf("every quiesce must unquiesce: %d stop(s) vs %d start(s)", pairs, got) + } + if got := l.breaker.failuresFor("felhom-pbs"); got != 1 { + t.Fatalf("only the FIRST tick should have attempted (and failed); consecutive failures = %d, want 1", got) + } +} + +// The backoff must EXPIRE — a breaker that latches open is a silent backup outage, which is worse +// than the loop it replaces. +func TestBreaker_RetriesAfterTheBackoffExpires(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 { // attempt 1 → fails, arms 15m + t.Fatal(err) + } + now = now.Add(breakerBaseDelay + time.Minute) // past the first backoff + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + if got := len(st.stoppedNames()); got != 2 { + t.Fatalf("after the backoff expired the tier must be retried: %d stop(s), want 2 — a permanent breaker is a silent outage", got) + } + if got := l.breaker.failuresFor("felhom-pbs"); got != 2 { + t.Fatalf("the retry also failed, so the count must climb: got %d, want 2", got) + } +} + +// ── SCENARIO B — backoff resets on success ─────────────────────────────────────────────────── +func TestBreaker_SuccessClearsTheBackoff(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) + + for i := 0; i < 3; i++ { // three failures, 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 l.breaker.failuresFor("felhom-pbs") != 3 { + t.Fatalf("setup: want 3 consecutive failures, got %d", l.breaker.failuresFor("felhom-pbs")) + } + + // The tier recovers. + be.mu.Lock() + be.phases["felhom-pbs"] = []string{phaseDone} + be.phaseIdx["felhom-pbs"] = 0 + be.mu.Unlock() + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + if got := l.breaker.failuresFor("felhom-pbs"); got != 0 { + t.Fatalf("a success must clear the backoff entirely; consecutive failures = %d, want 0", got) + } + + // And the very NEXT cycle must run — no lingering penalty. + before := len(st.stoppedNames()) + be.mu.Lock() + be.phaseIdx["felhom-pbs"] = 0 + be.mu.Unlock() + now = now.Add(5 * time.Minute) + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + if len(st.stoppedNames()) == before { + t.Fatal("after a success the next cycle must run immediately — a recovered box must carry no penalty") + } +} + +// ── SCENARIO F — one failing tier does not suppress the other ──────────────────────────────── +// +// COMPANION RED-PROOF (observed): make dropBackedOffTiers return nil when ANY tier is blocked (the +// tempting "global breaker" shape) and this fails with: +// +// "R-88 Scenario F: the healthy local tier was backed up 1 time(s) across 4 ticks; want >= 3" +// +// Restored. +func TestBreaker_OneFailingTierDoesNotSuppressAHealthyOne(t *testing.T) { + now := time.Date(2026, 7, 27, 9, 0, 0, 0, time.UTC) + be := tierBackendFailing("felhom-pbs", "local", "felhom-pbs") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + + const ticks = 4 + for i := 0; i < ticks; i++ { + if err := l.runOnce(context.Background()); err != nil { + t.Fatalf("tick %d: %v", i, err) + } + now = now.Add(5 * time.Minute) + } + + localRuns := 0 + be.mu.Lock() + for _, tr := range be.started { + if tr == "local" { + localRuns++ + } + } + be.mu.Unlock() + if localRuns < 3 { + t.Fatalf("R-88 Scenario F: the healthy local tier was backed up %d time(s) across %d ticks; want >= 3 — a broken tier must not halt a working one", + localRuns, ticks) + } + if l.breaker.failuresFor("local") != 0 { + t.Fatalf("the healthy tier must carry no failures; got %d", l.breaker.failuresFor("local")) + } +} + +// ── SCENARIO E — a manual trigger is never gated ───────────────────────────────────────────── +// +// TriggerNow bypasses due-ness and the window gate; it must bypass the breaker too. A human pressing +// „Mentés most" has made an explicit decision and must not be deferred by a scheduler's safety net. +func TestBreaker_ManualTriggerIsNeverGated(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 { // arm a backoff + t.Fatal(err) + } + if _, blocked := l.breaker.blocked("felhom-pbs", now); !blocked { + t.Fatal("setup: the tier should be in backoff") + } + before := len(st.stoppedNames()) + + if err := l.TriggerNow(); err != nil { + t.Fatalf("TriggerNow: %v", err) + } + deadline := time.Now().Add(3 * time.Second) + for time.Now().Before(deadline) { + if len(st.stoppedNames()) > before { + return // ran despite the active backoff — correct + } + time.Sleep(10 * time.Millisecond) + } + t.Fatal("a manual backup was deferred by the R-88 breaker; the human's explicit action must always run") +} + +// ── The backoff schedule is a contract, not an emergent property ───────────────────────────── +func TestBreaker_BackoffSchedule(t *testing.T) { + want := []time.Duration{ + 15 * time.Minute, 30 * time.Minute, time.Hour, 2 * time.Hour, 4 * time.Hour, + 4 * time.Hour, 4 * time.Hour, // capped, and it KEEPS retrying — never permanent + } + for i, w := range want { + if got := backoffFor(i + 1); got != w { + t.Errorf("backoffFor(%d) = %s, want %s", i+1, got, w) + } + } + if got := backoffFor(50); got != breakerMaxDelay { + t.Fatalf("a long-broken tier must stay at the cap and keep retrying, got %s", got) + } + if backoffFor(0) != 0 { + t.Fatal("no failures means no backoff") + } +} + +// The deferral is announced ONCE, when armed — not on every skipped tick. +func TestBreaker_LogsTheDeferralOncePerBackoff(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"}} + var buf strings.Builder + l := breakerLoop(t, be, st, &now) + l.logger = log.New(&buf, "", 0) + + for i := 0; i < 5; i++ { + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + now = now.Add(5 * time.Minute) + } + if n := strings.Count(buf.String(), "failed 1 time(s) in a row"); n != 1 { + t.Fatalf("the deferral must be logged ONCE per backoff period, got %d — a 5-minute loop logging every tick buries the signal", n) + } +} diff --git a/controller/internal/quiesce/invariant_test.go b/controller/internal/quiesce/invariant_test.go new file mode 100644 index 0000000..4a11fd3 --- /dev/null +++ b/controller/internal/quiesce/invariant_test.go @@ -0,0 +1,146 @@ +package quiesce + +import ( + "context" + "testing" + "time" +) + +// R-88 Part 3 — the invariant, pinned by name so a refactor has to delete an obviously-named +// contract to reintroduce the bug. See the comment block on scheduledRunAllowed. +// +// A missing value means UNKNOWN. Only a POSITIVE determination of "never backed up" may fire the +// safety valve. Prior instances of the opposite mistake: hub v0.12.0, v0.73.0, R-81, R-88. +// +// ── WHY ONLY HALF THE CONTRACT IS PINNED HERE ──────────────────────────────────────────────── +// +// Scenario C ("unknown must NOT bypass the window gate") is NOT testable in this package today, and +// writing a test that pretends otherwise would be worse than leaving it out. The agent returns +// byte-identical responses for "the storage read errored" and "there has never been a backup" — +// same Due, same Reason, same nil AgeSecs — so the controller has nothing to discriminate on. Giving +// "unknown" its own representation is an agent wire change, tracked as R-88 Part 2. +// +// What IS pinned here is Scenario D, and it is the half that a careless Part 2 would break. A fix +// that makes nil stop firing the valve — the obvious way to "fix C" — turns a loud bug into a silent +// one: a box powered on only outside its backup window would never back up at all, and nobody would +// notice for weeks. This test fails against that implementation. + +// agedBackend wraps tierBackend so DueFor can report a REAL age. The shared fake always returns nil +// ("never"), which is exactly the case under test here — so the control case needs its own shape +// rather than a field added to a fake three other suites depend on. +type agedBackend struct { + *tierBackend + ages map[string]*int64 +} + +func (a *agedBackend) DueFor(ctx context.Context, target string) (bool, *int64, error) { + due, _, err := a.tierBackend.DueFor(ctx, target) + return due, a.ages[target], err +} + +// SCENARIO D — a genuinely never-backed-up box still gets its first backup, outside the window. +// +// COMPANION RED-PROOF (observed): flip the nil branch of scheduledRunAllowed from `return true` to +// `return false` — i.e. apply "unknown must not bypass the gate" too broadly, which is precisely the +// over-correction Scenario C invites — and this fails with: +// +// "CONTRACT VIOLATED: a never-backed-up box outside its window did NOT back up (0 stack stop(s)) — +// the safety valve was removed; a box only ever powered on outside its window would starve" +// +// (DELETING the branch outright instead panics on the nil deref two lines down — the test still +// catches it, but `return false` is the mutation a real over-correction would produce.) +// +// Restored. +func TestContract_NeverBackedUp_RunsOutsideTheWindow(t *testing.T) { + // 12:00 Budapest, window 02:30 → gate [04:30, 08:30). Firmly outside. + outside := atBudapest(12, 0) + + be := newTierBackend() + be.tiers = []BackupTier{{Target: "local"}} + be.dueSet["local"] = true + be.phases["local"] = []string{phaseDone} + // DueFor returns a nil age — "never backed up" (see tierBackend.DueFor). + + st := &fakeStacks{running: []string{"bookstack"}} + l := windowLoop(t, be, st, "02:30", outside) + + if err := l.runOnce(context.Background()); err != nil { + t.Fatalf("runOnce: %v", err) + } + if got := len(st.stoppedNames()); got == 0 { + t.Fatalf("CONTRACT VIOLATED: a never-backed-up box outside its window did NOT back up (%d stack stop(s)) — "+ + "the safety valve was removed; a box only ever powered on outside its window would starve", got) + } +} + +// The control for the test above: with a RECENT backup, the same cycle at the same hour defers. +// Without this, TestContract_NeverBackedUp_RunsOutsideTheWindow would also pass against a gate that +// was simply disabled. +func TestContract_RecentBackup_DefersOutsideTheWindow(t *testing.T) { + outside := atBudapest(12, 0) + + be := newTierBackend() + be.tiers = []BackupTier{{Target: "local"}} + be.dueSet["local"] = true + be.phases["local"] = []string{phaseDone} + aged := &agedBackend{tierBackend: be, ages: map[string]*int64{"local": i64(20 * 3600)}} // 20h old + + st := &fakeStacks{running: []string{"bookstack"}} + l := windowLoop(t, aged, st, "02:30", outside) + + if err := l.runOnce(context.Background()); err != nil { + t.Fatalf("runOnce: %v", err) + } + if got := len(st.stoppedNames()); got != 0 { + t.Fatalf("a recently-backed-up box outside its window must DEFER, got %d stack stop(s) — "+ + "if this passes the gate is not actually gating anything", got) + } +} + +// The valve boundary as a truth table on the real predicate, named so it cannot be quietly dropped. +func TestContract_SafetyValveBoundary(t *testing.T) { + const window = "02:30" + outside := atBudapest(12, 0) + h := func(hours int64) *int64 { return i64(hours * 3600) } + + cases := []struct { + name string + age *int64 + want bool + }{ + {"never backed up (nil) → the valve FIRES", nil, true}, + {"just inside cadence+24h → defer", h(47), false}, + {"exactly at cadence+24h → defer (strictly greater)", h(48), false}, + {"past cadence+24h → the valve fires", h(49), true}, + } + for _, c := range cases { + if got := scheduledRunAllowed(outside, window, c.age, cadence24); got != c.want { + t.Errorf("CONTRACT VIOLATED: %s → scheduledRunAllowed = %v, want %v", c.name, got, c.want) + } + } +} + +// The breaker must not be able to starve a first-ever backup either: a never-backed-up tier that +// fails still backs off (it must — that is the whole point), but the backoff EXPIRES and it retries. +func TestContract_BreakerNeverStarvesAFirstBackup(t *testing.T) { + now := time.Date(2026, 7, 27, 12, 0, 0, 0, time.UTC) + be := tierBackendFailing("local", "local") + st := &fakeStacks{running: []string{"bookstack"}} + l := breakerLoop(t, be, st, &now) + + attempts := 0 + for i := 0; i < 4; i++ { + before := len(st.stoppedNames()) + if err := l.runOnce(context.Background()); err != nil { + t.Fatal(err) + } + if len(st.stoppedNames()) > before { + attempts++ + } + now = now.Add(backoffFor(i+1) + time.Minute) // step past each successive backoff + } + if attempts < 4 { + t.Fatalf("CONTRACT VIOLATED: a never-backed-up tier attempted only %d time(s) across 4 expired backoffs; "+ + "the breaker must bound the RETRY INTERVAL, never stop retrying", attempts) + } +} diff --git a/controller/internal/quiesce/quiesce.go b/controller/internal/quiesce/quiesce.go index 9e9e22a..2ba7847 100644 --- a/controller/internal/quiesce/quiesce.go +++ b/controller/internal/quiesce/quiesce.go @@ -100,6 +100,9 @@ type Loop struct { mu sync.Mutex // degradeOnce reports the pre-R-82 agent fallback exactly once per process (see tiers.go). degradeOnce sync.Once + // 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 } // New builds a Loop with sane defaults for any unset duration. @@ -124,6 +127,7 @@ func New(o Options) *Loop { poll: o.Poll, statusPoll: o.StatusPoll, maxQuiesce: o.MaxQuiesce, logger: o.Logger, now: time.Now, windowStartFn: o.WindowStartFn, cadence: o.Cadence, + breaker: newFailureBreaker(), } } @@ -189,6 +193,15 @@ func (l *Loop) runOnce(ctx context.Context) error { return nil } + // R-88 breaker — drop tiers whose backups keep failing, BEFORE anything is stopped. This is the + // gate that actually ends the app thrash: the harm was never the failing backup, it was the + // outage taken to attempt it. Per-tier, so a broken offsite tier leaves a healthy local one alone. + // SCHEDULED path only — TriggerNow never reaches here. + dueTiers = l.dropBackedOffTiers(dueTiers) + if len(dueTiers) == 0 { + return nil + } + // Window gate (Part 3) — SCHEDULED path only. TriggerNow calls quiesceAndPoll directly and is // never gated. Disabled when no window fn is wired (pre-v0.168.0 behavior). // @@ -207,6 +220,42 @@ func (l *Loop) runOnce(ctx context.Context) error { return l.quiesceAndPollTiers(ctx, dueTiers) } +// 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) { + 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) +} + +// 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) { + if l.breaker.recordSuccess(target) { + l.logger.Printf("[INFO] [quiesce] tier %s succeeded — clearing its failure backoff; normal cadence resumes", label) + } +} + +// dropBackedOffTiers removes tiers currently inside an R-88 backoff window. +// +// Silent by design at INFO: the deferral is announced ONCE, when the backoff is armed in +// quiesceAndPollTiers. Logging here would fire every 5 minutes for hours and bury the one line that +// matters — the same "a repeating log is not a signal" problem the loop itself had. +func (l *Loop) dropBackedOffTiers(tiers []dueTier) []dueTier { + now := l.now() + kept := make([]dueTier, 0, len(tiers)) + for _, t := range tiers { + if until, blocked := l.breaker.blocked(t.target, now); blocked { + l.logger.Printf("[DEBUG] [quiesce] tier %s is in backoff after %d consecutive failure(s) — not quiescing until %s", + tierLabel(t.target), l.breaker.failuresFor(t.target), until.Format(time.RFC3339)) + continue + } + kept = append(kept, t) + } + return kept +} + // oldestAge returns the largest (most overdue) age among the due tiers; nil when any tier has never // backed up (nil age = "never", which is maximally overdue and must win). func oldestAge(tiers []dueTier) *int64 { @@ -341,6 +390,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) if firstErr == nil { firstErr = fmt.Errorf("start backup on %s: %w", label, err) } @@ -358,8 +408,15 @@ func (l *Loop) quiesceAndPollTiers(ctx context.Context, tiers []dueTier) error { if perr != nil && firstErr == nil { firstErr = perr } - if phase == phaseFailed { + switch { + case phase == phaseFailed: l.logger.Printf("[WARN] [quiesce] tier %s: backup job %s failed", label, jobID) + l.noteTierFailure(t.target, label) + 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. + default: + l.noteTierSuccess(t.target, label) } if stillRunning { // The max-quiesce guard fired while THIS tier's backup is still going (a first full @@ -463,6 +520,36 @@ const ( // window [W+2h, W+6h); otherwise true ONLY if the safety valve holds — the newest successful backup is // missing (nil) or older than cadence+24h — so a box powered on only outside its window never starves. // An unparseable window fails OPEN (allow) rather than block backups forever. +// +// ── THE INVARIANT (R-88). READ THIS BEFORE TOUCHING THE nil BRANCH. ────────────────────────── +// +// A missing value means UNKNOWN. It does not mean zero, and it does not mean "never backed up". +// Only a POSITIVE determination of "never backed up" may fire the safety valve. +// +// This project has now made the opposite mistake four times, in four different packages: +// hub v0.12.0, hub v0.73.0, R-81 (hub `assessBackupFreshness`), and R-88 (here). Each time, the +// absence of a signal was read as a specific value, and each time the fix was the same shape: +// give "unknown" its own representation instead of letting it collapse into a real answer. +// +// ── WHAT IS AND IS NOT FIXED HERE ──────────────────────────────────────────────────────────── +// +// The nil branch below STILL fires the valve, and that is currently correct-by-necessity, not by +// design: the controller cannot yet tell the two apart. The agent's `/backup/due` returns +// BYTE-IDENTICAL responses for "the storage read errored" and "there has genuinely never been a +// backup" — same `Due: true`, same `Reason: "no successful backup recorded yet"`, same nil +// `AgeSecs`. The root cause is agent-side: `newestArchiveOn` (localapi/server.go) documents that +// errors "degrade to unknown, never to no-backup", but its `(time.Time, bool)` signature cannot +// represent unknown, so the error collapses into a positive claim of "never". +// +// Distinguishing them needs a new field on `/backup/due` plus a compat rule in both directions → +// tracked as its own task (R-88 Part 2, agent-side). Until then the R-88 BREAKER is what bounds the +// damage: an unknown-driven cycle may still run once outside the window, but it can no longer repeat +// every 5 minutes. +// +// DO NOT "fix" this by deleting the nil branch. Scenario D — a genuinely never-backed-up box that is +// only ever powered on outside its window — depends on it, and TestContract_NeverBackedUp_RunsOutside +// -TheWindow will fail if you do. Silencing the valve would trade a loud bug for a silent one: a box +// that never backs up at all, with nobody noticing for weeks. func scheduledRunAllowed(now time.Time, windowStart string, lastAgeSecs *int64, cadence time.Duration) bool { startMin, err := backupwindow.ParseHHMM(windowStart) if err != nil {