Files
felhom-controller/controller/internal/quiesce/breaker_test.go
T
admin 32200c7b5f R-88 Part 1: a failing backup stops re-quiescing (v0.176.0)
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.
2026-07-27 16:21:58 +02:00

255 lines
9.5 KiB
Go

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)
}
}