diff --git a/documentation/runbooks/workspace-CLAUDE.md b/documentation/runbooks/workspace-CLAUDE.md index 4b391a9..08de640 100644 --- a/documentation/runbooks/workspace-CLAUDE.md +++ b/documentation/runbooks/workspace-CLAUDE.md @@ -148,6 +148,24 @@ Kept so the old environment can be revived; **not the current setup**. - `claude-in-chrome` browser automation WAS available there (attaching only to sessions started after the bridge connected). +### Presence is not success + +A timestamp recording an **attempt** must never be read as evidence of a **result**. Where a status +field travels alongside a timestamp, the verdict consults both — or the timestamp records only +successes. + +| # | instance | what happened | +|---|---|---| +| 1 | **F-CRIT-2** | a phantom snapshot's ctime set tier freshness — an aborted 1-byte upload made the tier look backed up | +| 2 | **R-100** | `LastRun` is written on failure, so a nightly-failing offsite tier kept the staleness clock fresh forever | + +Both were found by asking of a timestamp: *what exactly must have happened for this to be set?* If the +answer is "we tried", it cannot answer "did it work". + +Corollary, from R-100's fix: when a verdict changes which field it counts from, **the alarm text has to +change with it**. Leaving the message reading `last run 8h ago` while alarming on a six-day-old success +turns a true alarm into one the operator dismisses. + ### A comment asserting an invariant needs a test pinning it, or it is a wish **Six instances in this project have shipped guarantees the code did not provide** — each survived diff --git a/hub/CHANGELOG.md b/hub/CHANGELOG.md index 7038007..f7924ac 100644 --- a/hub/CHANGELOG.md +++ b/hub/CHANGELOG.md @@ -1,3 +1,44 @@ +## v0.80.0 — R-100: staleness counts from the last SUCCESS (2026-07-28) + +`OffsiteChecker.isStale` counted from `last_run`, which the controller writes **unconditionally** at the +end of every run including failures. It therefore asked *"how long since we last TRIED"* — so a tier +failing on every single night refreshed the clock nightly and read as perfectly fresh forever. It now +counts from **`last_success`** (controller v0.181.0). + +**What the defect is NOT, corrected after checking.** The old comment here said *"a recent-but-failing +run is NOT stale (backup_failed owns that signal)"*, and that was **true** — `backup_failed` does fire +for a failing offsite run, nightly, and reaches the operator (live hub DB: 5 operator sends). The real +defect is **defeated defence in depth**: this checker is the hub-side, *pull-based* net that exists to be +independent of controller-*pushed* events, and anchoring it on a field the failing controller keeps +refreshing made it depend on the very thing it backs up. F-HUB — this campaign's own finding, the hub +dropping an event under `SQLITE_BUSY` with no retry — is exactly that loss. + +**Three branches, each deliberate:** +- **never ran** (no `last_run`) — unchanged v0.73.0 anchored behaviour. Still keyed on `last_run`, not + `last_success`, on purpose: `last_run` answers "has anything ever happened here", and a box whose + *first* run failed has a `last_run` and no `last_success` — that is a run, not a newborn. +- **legacy** (`last_run` set, no `last_success`) — degrades **explicitly** to the old `last_run` + behaviour, logged **once** per customer. Treating absence as failure would alarm the whole + un-upgraded fleet at once; treating it as success keeps the bug. Same degrade direction as R-88 + Part 2's `age_state`. +- **anchored** — counts from `last_success`. `last_status` is deliberately **not** consulted: + "error ⇒ stale" pages on every transient blip, which is the F-A1 noise path. One bad night is + tolerated because the threshold simply keeps running from the last good run. `running` is a real wire + value (a report captured mid-run) and is likewise not a verdict. + +**The alarm text had to change with the verdict.** `emitStale` still said `last run 8h ago` while firing +on a six-day-old success — a true alarm that reads as a false one. `staleAge` now separates the two +diagnoses: *"runs are happening and failing — check the error, not the schedule"* versus *"the offsite +leg is silently not running"*. `last_success` joins the event details. + +Fixtures are the **real** wire shapes from 4000 live reports (`ok` ×2269, absent ×541 always with an +empty `last_run`, `error` ×27, `running` ×7), not invented JSON. + +Red-proofs, all observed failing: restore the `last_run` anchor → `a tier that has not succeeded in 6 +days reads as FRESH`; delete the never-ran branch → `a newborn box alarmed`; collapse to +`last_status == "error"` → `a single transient failure alarmed`; delete the legacy degrade → `a legacy +controller alarmed — that is a fleet-wide alarm storm on an un-upgraded fleet`. + # Felhom Hub — Changelog ## v0.79.0 — R-97c: make the operator-only claim TRUE (2026-07-27) diff --git a/hub/internal/monitor/offsite.go b/hub/internal/monitor/offsite.go index add340e..fcfa635 100644 --- a/hub/internal/monitor/offsite.go +++ b/hub/internal/monitor/offsite.go @@ -27,7 +27,11 @@ type OffsiteChecker struct { logger *log.Logger onEvent EventNotifyFunc staleAfter time.Duration - now func() time.Time // injectable clock (tests) + + // legacyWarned tracks the one-shot R-100 legacy-degrade log, per customer. + legacyMu sync.Mutex + legacyWarned map[string]bool + now func() time.Time // injectable clock (tests) mu sync.Mutex fillStates map[string]string // customerID → fill band @@ -38,10 +42,13 @@ const defaultOffsiteStaleAfter = 48 * time.Hour // offsiteReport mirrors the controller report's `offsite` object (v0.109.0). type offsiteReport struct { - Enabled bool `json:"enabled"` - EscrowState string `json:"escrow_state"` - LastRun string `json:"last_run"` - LastStatus string `json:"last_status"` + Enabled bool `json:"enabled"` + EscrowState string `json:"escrow_state"` + LastRun string `json:"last_run"` + LastStatus string `json:"last_status"` + // LastSuccess (R-100) is the last run that actually SUCCEEDED — the staleness anchor. Absent on a + // controller older than v0.181.0; isStale degrades explicitly in that case, see there. + LastSuccess string `json:"last_success"` SnapshotCount int `json:"snapshot_count"` RepoSizeBytes int64 `json:"repo_size_bytes"` QuotaGB int `json:"quota_gb"` @@ -100,9 +107,20 @@ func (oc *OffsiteChecker) fillBand(off *offsiteReport) string { return bandForPercent(pct, 90, 95) } -// isStale: enabled + ESCROWED (the only state where runs are expected) with no run in >staleAfter (or -// never ran, ANCHORED — see below). Pending/disabled = normal onboarding, never stale. A -// recent-but-failing run is NOT stale (backup_failed owns that signal). +// isStale: enabled + ESCROWED (the only state where runs are expected) with no SUCCESSFUL run in +// >staleAfter (or never ran, ANCHORED — see below). Pending/disabled = normal onboarding, never stale. +// +// R-100 — PRESENCE IS NOT SUCCESS. This counted from `LastRun`, which the controller writes +// unconditionally at the end of every run INCLUDING failures. So it asked "how long since we last +// TRIED", and a tier failing on every single run refreshed the clock nightly and read as perfectly +// fresh forever. It now counts from `LastSuccess`, which only a successful run advances. +// +// The old comment here said "a recent-but-failing run is NOT stale (backup_failed owns that signal)", +// and that WAS true — `backup_failed` does fire, nightly, and reaches the operator. The defect is not +// silence, it is DEFEATED DEFENCE IN DEPTH: this checker is the hub-side, pull-based net that exists to +// be independent of controller-PUSHED events, and anchoring it on a field the failing controller keeps +// refreshing made it depend on the very thing it backs up. F-HUB (the hub dropping an event under +// SQLITE_BUSY, no retry) is exactly that loss. INVARIANT pinned by TestIsStale_* in offsite_r100_test.go. // // Part-7 (v0.73.0) — the never-ran branch no longer fires on sight. The 2026-07-23 cry-wolf: // demo-hp's tier was repaired and escrowed at 10:01Z and offsite_stale fired MINUTES later @@ -117,6 +135,11 @@ func (oc *OffsiteChecker) isStale(customerID string, off *offsiteReport) bool { if !off.Enabled || off.EscrowState != "escrowed" { return false } + // NEVER RAN AT ALL — unchanged v0.73.0 behaviour, and it must stay unchanged. A newborn box has no + // LastRun and no LastSuccess; alarming it on sight is the 2026-07-23 cry-wolf. Checked on LastRun + // (not LastSuccess) deliberately: LastRun is the "has anything ever happened here" signal, and a box + // whose first run FAILED has a LastRun but no LastSuccess — that is a run, not a newborn, and it + // belongs on the anchored path below. if off.LastRun == "" { anchor := oc.neverRanAnchor(customerID) if anchor.IsZero() { @@ -124,13 +147,52 @@ func (oc *OffsiteChecker) isStale(customerID string, off *offsiteReport) bool { } return oc.now().Sub(anchor) > oc.staleAfter } - t, err := time.Parse(time.RFC3339, off.LastRun) + + // LEGACY CONTROLLER — it has run, but sends no last_success (pre-v0.181.0). Handle it EXPLICITLY, + // in the direction that preserves known behaviour: count from LastRun exactly as before. + // - treating absence as FAILURE would alarm every un-upgraded box in the fleet at once; + // - treating it as SUCCESS is the bug. + // Preserving today's behaviour is correct here; the controller version floor drives the upgrade. + // Same degrade direction as R-88 Part 2's age_state, and for the same reason. + if off.LastSuccess == "" { + oc.warnLegacyOnce(customerID) + t, err := time.Parse(time.RFC3339, off.LastRun) + if err != nil { + return true // unparseable = unknown-old — fail toward visibility + } + return oc.now().Sub(t) > oc.staleAfter + } + + // THE ANCHORED VERDICT. Note what is NOT consulted: LastStatus. A single failed night does not make + // a tier stale — the threshold simply keeps running from the last good run, so one blip is tolerated + // and a persistent failure is caught. Reading LastStatus here ("error ⇒ stale") would alarm on every + // transient blip, which is the F-A1 noise path that trains an operator to ignore the alarm. + // `running` is a real wire value (a report captured mid-run) and is likewise none of our business. + t, err := time.Parse(time.RFC3339, off.LastSuccess) if err != nil { return true // unparseable = unknown-old — fail toward visibility } return oc.now().Sub(t) > oc.staleAfter } +// warnLegacyOnce logs the legacy degrade a single time per customer. Once, because this is a +// steady-state condition until the box upgrades — a per-cycle line would be pure noise — but it must be +// logged at all, so a fleet silently running on the old anchor is visible rather than assumed. +func (oc *OffsiteChecker) warnLegacyOnce(customerID string) { + oc.legacyMu.Lock() + defer oc.legacyMu.Unlock() + if oc.legacyWarned == nil { + oc.legacyWarned = map[string]bool{} + } + if oc.legacyWarned[customerID] { + return + } + oc.legacyWarned[customerID] = true + if oc.logger != nil { + oc.logger.Printf("[WARN] [offsite] %s: controller sends no last_success — staleness degraded to the last-ATTEMPT anchor (pre-v0.181.0 controller; a persistently failing tier will not go stale here until it upgrades)", customerID) + } +} + // neverRanAnchor returns the newest hub-held timestamp from which a never-ran-but-applied tier's // staleness may be counted (zero when the hub holds neither — the pre-v0.5x legacy shape). func (oc *OffsiteChecker) neverRanAnchor(customerID string) time.Time { @@ -258,16 +320,47 @@ func (oc *OffsiteChecker) emitFill(customerID string, off *offsiteReport, band s } } -func (oc *OffsiteChecker) emitStale(customerID string, off *offsiteReport) { - age := "never ran" - if off.LastRun != "" { - if t, err := time.Parse(time.RFC3339, off.LastRun); err == nil { - age = fmt.Sprintf("last run %s ago", oc.now().Sub(t).Round(time.Hour)) +// staleAge describes WHY the tier is stale, in the terms the verdict actually used. +// +// R-100: this must not say "last run 8h ago" while alarming, which is what it did when the verdict +// moved to the success anchor — a tier that RUNS nightly and FAILS nightly would have alarmed with a +// fresh-looking timestamp, and the operator would have read a true alarm as a false one. The two cases +// are genuinely different diagnoses and the message now separates them: +// - runs are not happening at all → check the schedule/controller +// - runs happen and FAIL → check the error; this is the case backup_failed also reports +func (oc *OffsiteChecker) staleAge(off *offsiteReport) (age, hint string) { + parse := func(v string) (time.Duration, bool) { + t, err := time.Parse(time.RFC3339, v) + if err != nil { + return 0, false } + return oc.now().Sub(t).Round(time.Hour), true } - message := fmt.Sprintf("Customer %s: offsite backup is STALE — enabled + escrowed but %s (threshold %s). The offsite leg is silently not running; check the controller/schedule", customerID, age, oc.staleAfter) + if off.LastSuccess == "" { + if d, ok := parse(off.LastRun); ok { + return fmt.Sprintf("no run has EVER succeeded (last attempt %s ago, status %q)", d, off.LastStatus), + " Runs are happening and failing — check the error, not the schedule" + } + return "never ran", " The offsite leg is silently not running; check the controller/schedule" + } + d, ok := parse(off.LastSuccess) + if !ok { + return "last successful run at an unparseable time", " Check the controller/schedule" + } + if la, ok := parse(off.LastRun); ok && off.LastRun != off.LastSuccess { + return fmt.Sprintf("last SUCCESSFUL run %s ago (it last attempted %s ago, status %q)", d, la, off.LastStatus), + " Runs are happening and failing — check the error, not the schedule" + } + return fmt.Sprintf("last successful run %s ago", d), + " The offsite leg is silently not running; check the controller/schedule" +} + +func (oc *OffsiteChecker) emitStale(customerID string, off *offsiteReport) { + age, hint := oc.staleAge(off) + message := fmt.Sprintf("Customer %s: offsite backup is STALE — enabled + escrowed but %s (threshold %s).%s", customerID, age, oc.staleAfter, hint) details, _ := json.Marshal(map[string]any{ - "customer_id": customerID, "last_run": off.LastRun, "last_status": off.LastStatus, "stale_after": oc.staleAfter.String(), + "customer_id": customerID, "last_run": off.LastRun, "last_success": off.LastSuccess, + "last_status": off.LastStatus, "stale_after": oc.staleAfter.String(), }) oc.logger.Printf("[INFO] Offsite staleness: %s (%s)", customerID, age) if _, err := oc.store.SaveEvent(customerID, "offsite_stale", "warning", message, string(details), "hub"); err != nil { diff --git a/hub/internal/monitor/offsite_r100_test.go b/hub/internal/monitor/offsite_r100_test.go new file mode 100644 index 0000000..b1fe311 --- /dev/null +++ b/hub/internal/monitor/offsite_r100_test.go @@ -0,0 +1,237 @@ +package monitor + +import ( + "encoding/json" + "io" + "log" + "strings" + "testing" + "time" +) + +// R-100 — PRESENCE IS NOT SUCCESS. +// +// isStale counted from `LastRun`, which the controller writes unconditionally at the end of EVERY run, +// failures included. So it asked "how long since we last TRIED", and a tier failing on every single +// night refreshed the clock nightly and read as perfectly fresh forever. +// +// The fixtures below are the REAL wire shapes, taken from 4000 live hub reports on 2026-07-28: +// last_status "ok" x2269 (always with last_run) · absent x541 (always with last_run EMPTY — +// never-ran) · "error" x27 (with last_run) · "running" x7 (a report captured mid-run). +// `running` is a real value and is neither success nor failure; the verdict must ignore it. + +// wire builds an offsiteReport by round-tripping JSON, so a field the struct cannot decode fails here +// rather than silently reading as its zero value. +func wire(t *testing.T, js string) *offsiteReport { + t.Helper() + var r struct { + Offsite *offsiteReport `json:"offsite"` + } + if err := json.Unmarshal([]byte(`{"offsite":`+js+`}`), &r); err != nil { + t.Fatalf("fixture does not decode: %v", err) + } + if r.Offsite == nil { + t.Fatal("fixture decoded to nil") + } + return r.Offsite +} + +// checkerAt builds a checker with a frozen clock over an empty real store (the constructor seeds from +// it, so it cannot be nil). Scenario B seeds that store; the other scenarios never reach the store, +// because only the never-ran branch consults it. +func checkerAt(t *testing.T, now time.Time) *OffsiteChecker { + t.Helper() + oc := NewOffsiteChecker(newNeverRanStore(t), 48*time.Hour, nil, log.New(io.Discard, "", 0)) + oc.now = func() time.Time { return now } + return oc +} + +// SCENARIO A — a persistently failing tier goes stale. +// +// This is the defect. Runs happen nightly and fail nightly; `last_run` is always fresh. +// +// RED-PROOF: restore the LastRun-only anchor (parse off.LastRun instead of off.LastSuccess in the +// final branch) → this fails with "a tier that has not succeeded in 6 days reads as FRESH". +func TestIsStale_PersistentlyFailingTierGoesStale(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + off := wire(t, `{ + "enabled": true, "escrow_state": "escrowed", + "last_run": "2026-07-28T02:15:00Z", + "last_success": "2026-07-22T02:15:00Z", + "last_status": "error" + }`) + if !checkerAt(t, now).isStale("demo-hp", off) { + t.Fatalf("a tier that has not succeeded in 6 days reads as FRESH — that is R-100 (last_run=%s last_success=%s)", + off.LastRun, off.LastSuccess) + } +} + +// SCENARIO B — a newborn box still does not alarm. The v0.73.0 cry-wolf must stay fixed; this is the +// branch most likely to be broken by accident here. +// +// RED-PROOF: delete the `off.LastRun == ""` never-ran branch → this fails with +// "a newborn box alarmed". +func TestIsStale_NewbornBoxDoesNotAlarm(t *testing.T) { + // The real never-ran shape: no last_run AND no last_status (541 live reports look like this). + off := wire(t, `{"enabled": true, "escrow_state": "escrowed"}`) + + // Delivery completed an hour ago — well inside the 48h grace. + st := newNeverRanStore(t) + seedConsumedSecret(t, st, "newborn", time.Hour) + var events []string + oc := neverRanChecker(st, &events) + if oc.isStale("newborn", off) { + t.Error("a newborn box alarmed — this is the 2026-07-23 cry-wolf that v0.73.0 fixed") + } + + // ...and once the grace elapses it DOES alarm, or the never-ran path would be a silence hole. + st2 := newNeverRanStore(t) + seedConsumedSecret(t, st2, "older", 72*time.Hour) + oc2 := neverRanChecker(st2, &events) + if !oc2.isStale("older", off) { + t.Error("a box that has never run 72h after delivery did NOT alarm — the never-ran path went silent") + } +} + +// SCENARIO C — a healthy tier reads fresh. +func TestIsStale_HealthyTierIsNotStale(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + off := wire(t, `{ + "enabled": true, "escrow_state": "escrowed", + "last_run": "2026-07-28T02:15:48Z", "last_success": "2026-07-28T02:15:48Z", "last_status": "ok" + }`) + if checkerAt(t, now).isStale("demo-hp", off) { + t.Error("a tier that succeeded 10h ago reads as stale — spurious alarm on a working tier") + } +} + +// SCENARIO D — ONE transient failure inside the threshold does NOT alarm. +// +// This is the over-correction guard. "LastStatus == error ⇒ stale" is the tempting one-line fix and it +// pages on every flaky night — the F-A1 noise path that trains an operator to ignore the alarm. +// +// RED-PROOF: collapse the verdict to `return off.LastStatus == "error"` → this fails with +// "a single transient failure alarmed". +func TestIsStale_SingleTransientFailureDoesNotAlarm(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + off := wire(t, `{ + "enabled": true, "escrow_state": "escrowed", + "last_run": "2026-07-28T02:15:00Z", + "last_success": "2026-07-27T16:00:00Z", + "last_status": "error" + }`) // last success 20h ago, threshold 48h + if checkerAt(t, now).isStale("demo-hp", off) { + t.Error("a single transient failure alarmed — 20h since the last success is well inside the 48h threshold (the F-A1 noise path)") + } +} + +// `running` is a real wire value (7 live reports). A report captured mid-run is neither a success nor a +// failure and must not move the verdict either way. +func TestIsStale_RunningStatusIsNotAVerdict(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + fresh := wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-28T02:16:58Z","last_success":"2026-07-28T02:15:00Z","last_status":"running"}`) + if checkerAt(t, now).isStale("demo-felhom", fresh) { + t.Error("a mid-run report on a healthy tier alarmed") + } + old := wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-28T02:16:58Z","last_success":"2026-07-20T02:15:00Z","last_status":"running"}`) + if !checkerAt(t, now).isStale("demo-felhom", old) { + t.Error("a mid-run report suppressed a genuinely stale tier — status must not be a verdict in either direction") + } +} + +// SCENARIO E — a LEGACY controller behaves exactly as today. +// +// It has run (last_run set) but sends no last_success. Treating that as failure would alarm every +// un-upgraded box in the fleet at once; treating it as success keeps the bug. It must degrade to the +// old LastRun behaviour, and say so once. +// +// RED-PROOF: delete the `off.LastSuccess == ""` degrade branch → the fresh legacy box falls through to +// the anchored verdict, parses "" as unparseable, and this fails with +// "a legacy controller alarmed — that is a fleet-wide alarm storm on an un-upgraded fleet". +func TestIsStale_LegacyControllerDegradesToTodaysBehaviour(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + + // Pre-v0.181.0 shape: no last_success key at all. + freshLegacy := wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-28T02:15:00Z","last_status":"ok"}`) + if freshLegacy.LastSuccess != "" { + t.Fatalf("fixture is not the legacy shape (last_success=%q)", freshLegacy.LastSuccess) + } + if checkerAt(t, now).isStale("legacy", freshLegacy) { + t.Error("a legacy controller alarmed — that is a fleet-wide alarm storm on an un-upgraded fleet") + } + + // And the old behaviour is genuinely preserved: an OLD last_run still goes stale. + staleLegacy := wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-20T02:15:00Z","last_status":"ok"}`) + if !checkerAt(t, now).isStale("legacy", staleLegacy) { + t.Error("a legacy controller with an 8-day-old run did NOT alarm — the degrade lost today's behaviour") + } +} + +// The legacy degrade must be VISIBLE — a fleet silently running on the old anchor is exactly the kind +// of thing that gets assumed rather than known — but only ONCE per customer, since it is a steady state. +func TestIsStale_LegacyDegradeIsLoggedOncePerCustomer(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + var buf strings.Builder + oc := NewOffsiteChecker(newNeverRanStore(t), 48*time.Hour, nil, log.New(&buf, "", 0)) + oc.now = func() time.Time { return now } + + off := wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-28T02:15:00Z","last_status":"ok"}`) + for i := 0; i < 5; i++ { + oc.isStale("legacy-a", off) + } + oc.isStale("legacy-b", off) + + out := buf.String() + if !strings.Contains(out, "no last_success") { + t.Fatalf("the legacy degrade was SILENT — a fleet on the old anchor would be invisible:\n%s", out) + } + if n := strings.Count(out, "legacy-a"); n != 1 { + t.Errorf("logged the degrade %d times for one customer, want 1 — it is a steady state, not an event", n) + } + if !strings.Contains(out, "legacy-b") { + t.Error("the second customer's degrade was suppressed — the once-guard must be per customer") + } +} + +// Disabled / not-yet-escrowed tiers are normal onboarding and never stale — unchanged, and pinned +// because the new branches sit above it. +func TestIsStale_DisabledOrPendingNeverStale(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + for _, js := range []string{ + `{"enabled":false,"escrow_state":"escrowed","last_run":"2026-07-01T02:15:00Z","last_success":"2026-07-01T02:15:00Z"}`, + `{"enabled":true,"escrow_state":"pending","last_run":"2026-07-01T02:15:00Z","last_success":"2026-07-01T02:15:00Z"}`, + } { + if checkerAt(t, now).isStale("c", wire(t, js)) { + t.Errorf("a disabled/pending tier alarmed: %s", js) + } + } +} + +// SCENARIO F (hub half) — the ALARM MUST NOT LIE. When the verdict moved to the success anchor, the +// message still read "last run 8h ago", so a tier running and failing nightly would have alarmed with a +// fresh-looking timestamp and been dismissed as a false positive. +func TestStaleAge_NamesTheRealReason(t *testing.T) { + now := time.Date(2026, 7, 28, 12, 0, 0, 0, time.UTC) + oc := checkerAt(t, now) + + // runs happening, failing + age, hint := oc.staleAge(wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-28T02:15:00Z","last_success":"2026-07-22T02:15:00Z","last_status":"error"}`)) + if strings.Contains(age, "last run 9h ago") || !strings.Contains(age, "SUCCESSFUL") { + t.Errorf("the alarm does not say the last SUCCESS is what is stale: %q", age) + } + if !strings.Contains(age, "attempted") || !strings.Contains(hint, "failing") { + t.Errorf("the alarm hides that runs ARE happening and failing — the operator would check the schedule instead of the error: %q / %q", age, hint) + } + + // never succeeded at all + age, hint = oc.staleAge(wire(t, `{"enabled":true,"escrow_state":"escrowed","last_run":"2026-07-28T02:15:00Z","last_status":"error"}`)) + if !strings.Contains(age, "EVER succeeded") || !strings.Contains(hint, "failing") { + t.Errorf("a never-succeeded tier is not described as such: %q / %q", age, hint) + } + + // genuinely not running + age, hint = oc.staleAge(wire(t, `{"enabled":true,"escrow_state":"escrowed"}`)) + if age != "never ran" || !strings.Contains(hint, "schedule") { + t.Errorf("a never-ran tier lost its schedule hint: %q / %q", age, hint) + } +}