Files
felhom-controller/controller/cmd/controller/bootwindow_test.go
T
admin dcc3363d2f
gates / gates (push) Successful in 9s
boot window: sample REFRESHES first — a cached fleet made 'settled' meaningless
Found by live validation on 9201, not by review. GetStacks() is the Manager's
in-memory map refreshed by the scheduler every 10s; sampling it every 5s without
refreshing means two identical samples can mean the cache did not update rather
than that the fleet settled. A container removed ~5s before the window closed was
still in the sampled fleet and the sweep logged 'no boot-orphaned apps' for an app
that had none. sampleBootFleet now refreshes first; a refresh error degrades
rather than aborting the window.
2026-08-02 20:17:12 +02:00

367 lines
15 KiB
Go

package main
import (
"context"
"io"
"log"
"strings"
"testing"
"time"
"gitea.dooplex.hu/admin/felhom-controller/internal/bootrecon"
"gitea.dooplex.hu/admin/felhom-controller/internal/stacks"
)
// R-157 mechanism A — the sweep that looked once.
//
// TIMING IS NOT TESTED BY SLEEPING (§10). The window's constants are package vars, so each test
// shrinks them to sub-millisecond values: the CONTRACT under test is "how many samples, and what
// ends the window", not "how long a second is". A test that waited real seconds would be slow,
// flaky, and would still not prove the contract.
// windowStacks is a StackProvider whose fleet CHANGES over successive GetStacks() calls — which is
// the whole point: the pre-v0.190.0 sweep sampled once and could not see a late settler.
type windowStacks struct {
// frames is the fleet as seen on each successive GetStacks() call; the last frame repeats.
frames [][]stacks.Stack
calls int
starts map[string]int
onStart func(*windowStacks, string)
refreshes int
refreshErr error
// cycle makes the fleet NEVER settle: frames repeat forever instead of the last one sticking.
// Required by the budget test — with frames that eventually stop changing, the window terminates
// by SETTLING even with the budget removed, so the red-proof would not reach the hang it exists
// to demonstrate.
cycle bool
}
func (w *windowStacks) GetStacks() []stacks.Stack {
i := w.calls
w.calls++
if i >= len(w.frames) {
if w.cycle {
i = i % len(w.frames)
} else {
i = len(w.frames) - 1
}
}
return w.frames[i]
}
func (w *windowStacks) RefreshStatus() error {
w.refreshes++
if w.refreshErr != nil {
return w.refreshErr
}
return nil
}
func (w *windowStacks) StartStack(name string) error {
if w.starts == nil {
w.starts = map[string]int{}
}
w.starts[name]++
if w.onStart != nil {
w.onStart(w, name)
}
return nil
}
// shrinkWindow makes the window fast and deterministic, and restores the shipped values after.
func shrinkWindow(t *testing.T, sample time.Duration, stableFor int, budget time.Duration) {
t.Helper()
os, ost, ob, osettle := bootReconcileSample, bootReconcileStableFor, bootReconcileBudget, bootReconcileSettle
t.Cleanup(func() {
bootReconcileSample, bootReconcileStableFor, bootReconcileBudget, bootReconcileSettle = os, ost, ob, osettle
})
bootReconcileSample, bootReconcileStableFor, bootReconcileBudget = sample, stableFor, budget
bootReconcileSettle = time.Millisecond
}
// captureSweep replaces the sweep with a recorder and returns the fleet it was handed.
func captureSweep(t *testing.T) *[][]stacks.Stack {
t.Helper()
orig := bootReconcileFn
t.Cleanup(func() { bootReconcileFn = orig })
var seen [][]stacks.Stack
bootReconcileFn = func(_ context.Context, mgr bootrecon.StackProvider, _ *log.Logger) bootrecon.Result {
seen = append(seen, mgr.GetStacks())
return bootrecon.Result{}
}
return &seen
}
func upStack(name string) stacks.Stack {
return stacks.Stack{
Name: name, Deployed: true, State: stacks.StateRunning,
Containers: []stacks.ContainerInfo{{Name: name, State: stacks.StateRunning}},
AppConfig: &stacks.AppConfig{Deployed: true, DesiredState: stacks.DesiredStateRunning},
}
}
// settlingLate is the R-157-A shape: at T+5s the app is still `starting` with its containers coming
// up, and it only comes to rest in a DOWN state later.
func settlingLate(name string) stacks.Stack {
return stacks.Stack{
Name: name, Deployed: true, State: stacks.StateStarting,
Containers: []stacks.ContainerInfo{{Name: name, State: stacks.StateStarting}},
AppConfig: &stacks.AppConfig{Deployed: true, DesiredState: stacks.DesiredStateRunning},
}
}
func settledDown(name string) stacks.Stack {
return stacks.Stack{
Name: name, Deployed: true, State: stacks.StateExited,
Containers: []stacks.ContainerInfo{{Name: name, State: stacks.StateExited}},
AppConfig: &stacks.AppConfig{Deployed: true, DesiredState: stacks.DesiredStateRunning},
}
}
// --- Group A / Scenario B — a late settler IS swept -----------------------------------------------
func TestBootWindow_LateSettlerIsSweptOnASettledFleet(t *testing.T) {
// The fleet is still moving for the first frames and settles only later. The sweep must run
// AFTER it settles and must be handed the SETTLED fleet — because the pre-v0.190.0 defect was a
// candidate set derived from a fleet that had not finished moving.
//
// RED-PROOF: restore the single-sweep shape (delete the sampling loop so runBootReconcile calls
// bootReconcileFn straight after the settle delay) and this test fails — the sweep is handed the
// `starting` frame, in which the app is not a down-state candidate at all.
// Demonstrated in REPORT.md §4.
shrinkWindow(t, time.Millisecond, 2, 500*time.Millisecond)
seen := captureSweep(t)
w := &windowStacks{frames: [][]stacks.Stack{
{settlingLate("immich")}, // T+5s: still coming up
{settlingLate("immich")},
{settledDown("immich")}, // settles into a down state only now
{settledDown("immich")},
{settledDown("immich")},
}}
runBootReconcile(context.Background(), w, log.New(io.Discard, "", 0))
if len(*seen) != 1 {
t.Fatalf("the sweep ran %d times, want exactly 1 — the window samples, it does not sweep per sample", len(*seen))
}
got := (*seen)[0]
if len(got) != 1 || got[0].State != stacks.StateExited {
t.Fatalf("the sweep was handed state=%v, want the SETTLED (exited) fleet — a candidate set "+
"derived from a still-moving fleet is exactly the R-157 mechanism-A defect", got)
}
}
func TestBootWindow_SweepRunsExactlyOnceEvenOnAQuietBoot(t *testing.T) {
shrinkWindow(t, time.Millisecond, 2, 500*time.Millisecond)
seen := captureSweep(t)
w := &windowStacks{frames: [][]stacks.Stack{{upStack("bookstack")}}}
runBootReconcile(context.Background(), w, log.New(io.Discard, "", 0))
if len(*seen) != 1 {
t.Fatalf("sweeps=%d, want exactly 1 on a quiet boot", len(*seen))
}
}
// --- Group B / Scenario C — the window TERMINATES -------------------------------------------------
func TestBootWindow_BudgetEndsAForeverChangingFleet(t *testing.T) {
// A fleet that never stops changing must not sample forever. The budget ends it, the sweep runs
// once anyway (a churning box is exactly the box that needs it), and the log SAYS the budget
// ended it — "settled and found nothing" and "ran out of time" are different facts.
//
// RED-PROOF: remove the `time.Since(started) < bootReconcileBudget` loop condition and this test
// hangs — the unbounded-loop shape §5 bans. Demonstrated in REPORT.md §4 (observed as a timeout).
shrinkWindow(t, time.Millisecond, 3, 30*time.Millisecond)
seen := captureSweep(t)
var buf strings.Builder
// Every frame differs, so `stable` can never reach stableFor.
frames := make([][]stacks.Stack, 0, 200)
for i := 0; i < 200; i++ {
s := upStack("immich")
s.Containers = make([]stacks.ContainerInfo, i%7) // container count changes every sample
frames = append(frames, []stacks.Stack{s})
}
w := &windowStacks{frames: frames, cycle: true}
done := make(chan struct{})
go func() {
runBootReconcile(context.Background(), w, log.New(&buf, "", 0))
close(done)
}()
select {
case <-done:
case <-time.After(5 * time.Second):
t.Fatal("runBootReconcile did not terminate on a forever-changing fleet — this is the " +
"unbounded restart-loop shape the package's own boundary forbids")
}
if len(*seen) != 1 {
t.Fatalf("sweeps=%d, want exactly 1 after the budget expired", len(*seen))
}
if out := buf.String(); !strings.Contains(out, "budget") {
t.Fatalf("the log does not say the BUDGET ended the window, so a churning boot reads like a "+
"quiet one:\n%s", out)
}
}
func TestBootWindow_SettledPathSaysSettled(t *testing.T) {
shrinkWindow(t, time.Millisecond, 2, 500*time.Millisecond)
captureSweep(t)
var buf strings.Builder
w := &windowStacks{frames: [][]stacks.Stack{{upStack("docmost")}}}
runBootReconcile(context.Background(), w, log.New(&buf, "", 0))
out := buf.String()
if !strings.Contains(out, "settled") {
t.Fatalf("a settled window must say so — otherwise it is indistinguishable from a budget "+
"expiry:\n%s", out)
}
if strings.Contains(out, "budget") {
t.Fatalf("a settled window must NOT claim the budget ended it:\n%s", out)
}
}
func TestBootWindow_CancelledContextStopsImmediately(t *testing.T) {
shrinkWindow(t, time.Millisecond, 3, time.Second)
seen := captureSweep(t)
ctx, cancel := context.WithCancel(context.Background())
cancel()
runBootReconcile(ctx, &windowStacks{frames: [][]stacks.Stack{{upStack("x")}}}, log.New(io.Discard, "", 0))
if len(*seen) != 0 {
t.Fatalf("the sweep ran %d times on a cancelled context, want 0", len(*seen))
}
}
// --- Group C / Scenario D — a customer's Stop survives the WIDENED window -------------------------
func TestBootWindow_CustomerStoppedAppSurvivesEveryPass(t *testing.T) {
// THE REGRESSION THIS TASK COULD INTRODUCE. A longer window means more chances to resurrect an
// app the customer deliberately stopped. It must survive the whole window — this drives the REAL
// bootrecon sweep (not the captured stub), so the desired-state check is genuinely exercised.
//
// RED-PROOF: drop the DesiredStateStopped branch from isBootOrphan (make it fall through to the
// running case) and this test fails with a start count of 1. Demonstrated in REPORT.md §4.
shrinkWindow(t, time.Millisecond, 2, 200*time.Millisecond)
stopped := stacks.Stack{
Name: "nextcloud", Deployed: true, State: stacks.StateStopped, Containers: nil,
AppConfig: &stacks.AppConfig{Deployed: true, DesiredState: stacks.DesiredStateStopped},
}
// The fleet churns around it, so the window runs many passes before settling.
frames := [][]stacks.Stack{
{stopped, settlingLate("immich")},
{stopped, settlingLate("immich")},
{stopped, settledDown("immich")},
{stopped, upStack("immich")},
{stopped, upStack("immich")},
{stopped, upStack("immich")},
}
w := &windowStacks{frames: frames, onStart: func(w *windowStacks, _ string) {}}
runBootReconcile(context.Background(), w, log.New(io.Discard, "", 0))
if n := w.starts["nextcloud"]; n != 0 {
t.Fatalf("the customer-stopped app was started %d time(s) by the widened window — this is the "+
"regression a longer window makes possible and it is the worst outcome available here", n)
}
}
// --- §8.3 — a late recovery is REPORTED, never hidden ---------------------------------------------
func TestRecordLateRecovery_WarnsWhenTheGraceHasAlreadyExpired(t *testing.T) {
var buf strings.Builder
lg := log.New(&buf, "", 0)
// started far enough back that settle + elapsed exceeds the 90 s grace
recordLateRecovery(lg, time.Now().Add(-(deadAppBootGrace + 10*time.Second)), bootrecon.Result{Recovered: []string{"immich"}})
out := buf.String()
if !strings.Contains(out, "LATE RECOVERY") || !strings.Contains(out, "immich") {
t.Fatalf("a recovery past the dead-app grace must be reported by name — otherwise a stale "+
"alarm stands with no counter-evidence (§8.3):\n%s", out)
}
}
func TestRecordLateRecovery_SilentInsideTheGrace(t *testing.T) {
var buf strings.Builder
recordLateRecovery(log.New(&buf, "", 0), time.Now(), bootrecon.Result{Recovered: []string{"immich"}})
if buf.Len() != 0 {
t.Fatalf("a recovery INSIDE the grace must stay silent — that is what makes a successful "+
"recovery invisible to the customer:\n%s", buf.String())
}
}
func TestRecordLateRecovery_SilentWhenNothingRecovered(t *testing.T) {
var buf strings.Builder
recordLateRecovery(log.New(&buf, "", 0), time.Now().Add(-time.Hour), bootrecon.Result{})
if buf.Len() != 0 {
t.Fatalf("nothing was recovered, so there is nothing late to report:\n%s", buf.String())
}
}
// --- The window's constants must fit the grace they are justified against -------------------------
func TestBootWindow_CommonCaseFitsInsideTheDeadAppGrace(t *testing.T) {
// The comment on the window constants justifies them against deadAppBootGrace. A comment
// asserting an invariant needs a test pinning it, or it is a wish.
common := bootReconcileSettle + bootReconcileBudget + bootrecon.DefaultRetryDelay
if common > deadAppBootGrace {
t.Fatalf("settle(%s) + budget(%s) + one retry(%s) = %s exceeds the %s dead-app grace — the "+
"COMMON case must stay silent, or every slow boot alerts",
bootReconcileSettle, bootReconcileBudget, bootrecon.DefaultRetryDelay, common, deadAppBootGrace)
}
if bootReconcileSample <= 0 || bootReconcileStableFor < 2 {
t.Fatalf("sample=%s stableFor=%d — one sample cannot distinguish 'settled' from 'sampled "+
"between two docker events'", bootReconcileSample, bootReconcileStableFor)
}
}
// --- the sample must observe REALITY, not the Manager's cache ------------------------------------
func TestBootWindow_EverySampleRefreshesTheStatus(t *testing.T) {
// FOUND BY LIVE VALIDATION, not review. GetStacks() returns the Manager's in-memory map, which
// the scheduler refreshes on its own 10 s cadence. Sampling every 5 s WITHOUT refreshing means two
// consecutive samples can be identical because the cache did not update — so the window declares
// "settled" on stale data and sweeps on a picture of the box from up to 10 s ago. On 9201 a
// container removed ~5 s before the window closed was still in the sampled fleet, and the sweep
// logged "no boot-orphaned apps" for an app that had none.
//
// RED-PROOF: delete the `_ = mgr.RefreshStatus()` line from sampleBootFleet and this test fails
// with refreshes=0. Demonstrated in REPORT.md §4.
shrinkWindow(t, time.Millisecond, 3, 500*time.Millisecond)
captureSweep(t)
w := &windowStacks{frames: [][]stacks.Stack{{upStack("immich")}}}
runBootReconcile(context.Background(), w, log.New(io.Discard, "", 0))
if w.refreshes < 3 {
t.Fatalf("the window refreshed %d time(s) for %d samples — every sample must observe reality, "+
"or 'settled' can mean 'the cache did not update'", w.refreshes, w.calls)
}
// calls includes ONE extra GetStacks from the captured sweep itself, which does not sample.
if w.refreshes != w.calls-1 {
t.Fatalf("refreshes=%d but samples=%d — each sample must refresh exactly once before reading",
w.refreshes, w.calls-1)
}
}
func TestBootWindow_RefreshErrorDoesNotStopTheWindow(t *testing.T) {
// A boot window that cannot reach docker is exactly when a stale verdict is most dangerous, but
// giving up entirely would leave the sweep un-run. Degrade, do not abort.
shrinkWindow(t, time.Millisecond, 2, 200*time.Millisecond)
seen := captureSweep(t)
w := &windowStacks{frames: [][]stacks.Stack{{upStack("immich")}}, refreshErr: errRefresh{}}
runBootReconcile(context.Background(), w, log.New(io.Discard, "", 0))
if len(*seen) != 1 {
t.Fatalf("sweeps=%d, want 1 — a refresh error must not abort the window", len(*seen))
}
}
type errRefresh struct{}
func (errRefresh) Error() string { return "docker unreachable" }