From 6da3a7d866f60baec3fe4a7e0eeb7c30bfe464b2 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Mon, 5 Oct 2026 09:24:14 +0200 Subject: [PATCH] hub v0.134.0: a down box is judged on longer missed-backup lines (R-872); household outage mail at most weekly (R-873); backup_catchup_done allowed (R-871) Co-Authored-By: Claude Opus 5.5 (1M context) Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS --- hub/CHANGELOG.md | 16 ++++ hub/internal/api/handler.go | 4 + hub/internal/api/r871_catchup_event_test.go | 12 +++ hub/internal/monitor/deadline.go | 81 ++++++++++++++++- hub/internal/monitor/r872_down_box_test.go | 86 +++++++++++++++++++ hub/internal/notify/dispatcher.go | 25 ++++++ .../notify/r873_liveness_weekly_test.go | 55 ++++++++++++ 7 files changed, 278 insertions(+), 1 deletion(-) create mode 100644 hub/internal/api/r871_catchup_event_test.go create mode 100644 hub/internal/monitor/r872_down_box_test.go create mode 100644 hub/internal/notify/r873_liveness_weekly_test.go diff --git a/hub/CHANGELOG.md b/hub/CHANGELOG.md index d46f1986..30bc7ee8 100644 --- a/hub/CHANGELOG.md +++ b/hub/CHANGELOG.md @@ -1,3 +1,19 @@ +## v0.134.0 — a box that is off at night: the missed-backup alarm judges a down box; the household hears an outage at most weekly; the catch-up line is allowed (R-872, R-873, R-871) (2026-10-05) + +**Controller v0.295.0** sends `backup_catchup_done`; an older controller never does. + +- **R-872 (`08` §6.4).** The 05:00 deadline check no longer skips a customer whose node is `down`. A box down at + EVERY deadline (a laptop switched off at night — measured 2026-10-05: `1 skipped (down)`) was never judged. A down + box is now judged on longer lines: `expected_dbdump_missed` after 48 h without `db_dump_completed`, + `expected_backup_missed` after 72 h without a whole-guest backup in any retained host report, and nothing for a box + first seen less than 48 h ago. A box that died last night still raises only its staleness alarm. `disabled` boxes are + still skipped (R-321). `monitor/r872_down_box_test.go`, 3 red-proofs. +- **R-873 (`08` §6.4).** "Your server cannot be reached" (`node_stale`, `node_down`, `host_stale`, `host_down`) reaches the + HOUSEHOLD at most once per 7 days, read from the persisted notification log; the operator still gets every edge; the + recovery mail stays paired (a held-back down mail also holds back its recovery). `notify/r873_liveness_weekly_test.go`. +- **R-871.** `backup_catchup_done` is an allowed event type (info: recorded, never mailed). +- CC decisions 115–116 (`09` §3), operator may reverse. + ## v0.133.0 — test approvals end with the test (R-859); the root-file bundle on the System page, in the install manifest, and its alarm (R-840) (2026-10-04) **Agent v0.143.0** reports the bundle; an older agent shows `unknown` in the new column (never a guess). diff --git a/hub/internal/api/handler.go b/hub/internal/api/handler.go index 06867f6f..c8dc75e9 100644 --- a/hub/internal/api/handler.go +++ b/hub/internal/api/handler.go @@ -2050,6 +2050,10 @@ var allowedEventTypes = map[string]bool{ // of memory. Household + operator; hu AND en `mail.event.*`; per-app cooldown on both legs. "app_stopped_unhealthy": true, + // R-871 (v0.134.0, controller v0.295.0, `09` decision 109): the box was off at its backup time and made the + // missed backups when it came back. Info — recorded on the box's timeline, never mailed. + "backup_catchup_done": true, + // Controller-pushed events "controller_started": true, "claim_lockout": true, // v0.50.0 — claim/reset code brute-force lockout tripped diff --git a/hub/internal/api/r871_catchup_event_test.go b/hub/internal/api/r871_catchup_event_test.go new file mode 100644 index 00000000..b840451c --- /dev/null +++ b/hub/internal/api/r871_catchup_event_test.go @@ -0,0 +1,12 @@ +package api + +import "testing" + +// R-871 (v0.134.0): the box's "missed backup made now" line (controller v0.295.0, event backup_catchup_done) must be +// an allowed type, or POST /event answers 400 and the household's timeline line vanishes (hub-event-allowlist trap). +// COMPANION RED-PROOF: remove "backup_catchup_done" from allowedEventTypes → this fails. +func TestR871_CatchUpEventIsAllowed(t *testing.T) { + if !allowedEventTypes["backup_catchup_done"] { + t.Fatal("backup_catchup_done is not an allowed event type — the box's catch-up line would be dropped with a 400") + } +} diff --git a/hub/internal/monitor/deadline.go b/hub/internal/monitor/deadline.go index 51503b0a..c12d79de 100644 --- a/hub/internal/monitor/deadline.go +++ b/hub/internal/monitor/deadline.go @@ -334,6 +334,68 @@ func stalenessState(staleness *StalenessChecker, customerID string) string { return staleness.GetState(customerID) } +// downDumpMissedAfter / downBackupMissedAfter (R-872): the lines a DOWN box is judged on. 48 h = two nights without +// a database dump (a box that died last night is the staleness alarm's alone). 72 h for the whole-guest backup = the +// agent's own catch-up valve (cadence 24 h + 24 h) plus a day. Decided by CC — operator may reverse. +const ( + downDumpMissedAfter = 48 * time.Hour + downBackupMissedAfter = 72 * time.Hour +) + +// judgeDownCustomer is R-872's judgement of a box that is down at the deadline. It raises at most one +// expected_dbdump_missed and one expected_backup_missed, each only past its longer line, and never for a box that +// was bound or first reported less than downDumpMissedAfter ago (nothing has been expected yet). +func judgeDownCustomer(s *store.Store, id string, now time.Time, onEvent EventNotifyFunc, logger *log.Logger) (backupMissed, dbdumpMissed int) { + if bound, err := s.HasEverBoundHost(id); err == nil && !bound { + return 0, 0 + } + first, ferr := s.GetFirstHostReportAt(id) + if ferr != nil || first.IsZero() || now.Sub(first) < downDumpMissedAfter { + return 0, 0 + } + raise := func(typ, msg string) { + if _, err := s.SaveEvent(id, typ, "error", msg, "{}", "hub"); err != nil { + logger.Printf("[WARN] Failed to save %s for %s: %v", typ, id, err) + } else if onEvent != nil { + onEvent(id, typ, "error", msg, "{}", "hub") + } + } + // Database dumps: the newest db_dump_completed in the last 7 days. + if dumps, err := s.GetEventsByType(id, "db_dump_completed", now.Add(-backupEvidenceLookback)); err == nil { + var newest time.Time + for _, e := range dumps { + if e.CreatedAt.After(newest) { + newest = e.CreatedAt + } + } + if newest.IsZero() || now.Sub(newest) > downDumpMissedAfter { + last := "none in the last 7 days" + if !newest.IsZero() { + last = newest.UTC().Format(time.RFC3339) + } + raise("expected_dbdump_missed", fmt.Sprintf("No DB dump for over %s while the box is down at its deadline (last: %s) — it may be switched off at its backup time (R-872)", + downDumpMissedAfter, last)) + dbdumpMissed = 1 + } + } + // Whole-guest backup: the newest backup any retained host report shows. + if rows, err := s.GetHostReportsSince(id, now.Add(-backupEvidenceLookback)); err == nil { + newest, have := newestBackupEvidence(rows, now) + if !have || now.Sub(newest) > downBackupMissedAfter { + last := "none in the last 7 days" + if have { + last = newest.UTC().Format(time.RFC3339) + } + raise("expected_backup_missed", fmt.Sprintf("No fresh verified backup for over %s while the box is down at its deadline (last: %s) (R-872)", + downBackupMissedAfter, last)) + backupMissed = 1 + } + } + logger.Printf("[INFO] Deadline check: %s is DOWN — judged on the longer lines (dump %s, whole-guest %s): dump missed=%d backup missed=%d", + id, downDumpMissedAfter, downBackupMissedAfter, dbdumpMissed, backupMissed) + return backupMissed, dbdumpMissed +} + func CheckBackupDeadlines(s *store.Store, staleness *StalenessChecker, onEvent EventNotifyFunc, logger *log.Logger) { customerIDs, err := s.GetActiveCustomerIDs() if err != nil { @@ -357,7 +419,24 @@ func CheckBackupDeadlines(s *store.Store, staleness *StalenessChecker, onEvent E // `expected_backup_missed` / `expected_dbdump_missed` every morning about a machine we asked // to be quiet. That is R-195's shape exactly — a skip keyed off the wrong fact missing the // customer it would most obviously cover — which is why both doors are closed together. - if st := stalenessState(staleness, id); st == "down" || st == StateDisabled { + st := stalenessState(staleness, id) + if st == StateDisabled { + skipped++ + continue + } + // R-872 (v0.134.0): a box that is DOWN at 05:00 is no longer skipped outright. It was, so that a box that + // just died raises its staleness alarm and not a backup alarm too — but a box that is down at EVERY + // deadline (a laptop switched off at night, Tester 2, measured 2026-10-05: "1 skipped (down)") was then + // never judged at all, and its missing backups stayed silent for ever. A down box is now judged on a + // LONGER line (downDumpMissedAfter / downBackupMissedAfter): a box that died last night still raises only + // its staleness alarm; a box that has gone two nights without a dump raises the backup alarm, down or not. + // Pinned by TestR872_*. + if st == "down" { + if !s.IsCustomerBlocked(id) { + b, d := judgeDownCustomer(s, id, time.Now().UTC(), onEvent, logger) + backupMissed += b + dbdumpMissed += d + } skipped++ continue } diff --git a/hub/internal/monitor/r872_down_box_test.go b/hub/internal/monitor/r872_down_box_test.go new file mode 100644 index 00000000..1f54d830 --- /dev/null +++ b/hub/internal/monitor/r872_down_box_test.go @@ -0,0 +1,86 @@ +package monitor + +import ( + "database/sql" + "io" + "log" + "testing" + "time" + + "gitea.dooplex.hu/admin/felhom-hub/internal/store" +) + +// R-872 (v0.134.0) — a box DOWN at the 05:00 deadline is judged on longer lines instead of being skipped. +// THE MEASURED SHAPE (Tester 2, 2026-10-05 05:00 Budapest): "Deadline check: … 0 backup missed … 1 skipped (down)" — +// a laptop off at every deadline, no dump ever, no alarm ever. +// COMPANION RED-PROOF: restore `if st == "down" || st == StateDisabled { skipped++; continue }` → the Tester 2 +// shape raises nothing. + +func downBox(t *testing.T, firstReportAge time.Duration) (*store.Store, string, *StalenessChecker) { + t.Helper() + st, path := seedStalenessCustomer(t, "ok", 3*time.Hour) // the controller report is 3 h old → down + if err := st.UpsertHost(&store.Host{HostID: "h1", CustomerID: "c1", APIKey: "k1"}); err != nil { + t.Fatal(err) + } + if err := st.SaveHostReport("h1", "c1", []byte(`{"pbs_snapshots":[],"backups":[]}`), store.HostReportDenorm{}); err != nil { + t.Fatal(err) + } + r872Backdate(t, path, "UPDATE host_reports SET received_at = ?", time.Now().UTC().Add(-firstReportAge)) + sc, _ := newChecker(t, st) + sc.Check() + if sc.GetState("c1") != "down" { + t.Fatalf("setup: state %q, want down", sc.GetState("c1")) + } + return st, path, sc +} + +func r872Backdate(t *testing.T, path, q string, at time.Time) { + t.Helper() + db, err := sql.Open("sqlite", path) + if err != nil { + t.Fatal(err) + } + defer db.Close() + if _, err := db.Exec(q, at.Format("2006-01-02 15:04:05")); err != nil { + t.Fatal(err) + } +} + +func deadlineEvents(st *store.Store, sc *StalenessChecker) map[string]int { + got := map[string]int{} + CheckBackupDeadlines(st, sc, func(cid, et, sev, msg, det, src string) { got[et]++ }, log.New(io.Discard, "", 0)) + return got +} + +// Tester 2's shape: bound 5 days ago, down at every deadline, no dump, no backup → both alarms. +func TestR872_DownEveryNightRaisesTheMissedAlarms(t *testing.T) { + st, _, sc := downBox(t, 5*24*time.Hour) + got := deadlineEvents(st, sc) + if got["expected_dbdump_missed"] != 1 || got["expected_backup_missed"] != 1 { + t.Fatalf("events %v — a box off at every deadline must raise the missed-backup alarms, down or not", got) + } +} + +// A box that went down last night but made its dump yesterday evening (the catch-up) → no alarm (staleness owns it). +func TestR872_DownWithARecentDumpIsQuiet(t *testing.T) { + st, path, sc := downBox(t, 5*24*time.Hour) + if _, err := st.SaveEvent("c1", "db_dump_completed", "info", "ok", "{}", "controller"); err != nil { + t.Fatal(err) + } + r872Backdate(t, path, "UPDATE events SET created_at = ? WHERE event_type = 'db_dump_completed'", time.Now().UTC().Add(-20*time.Hour)) + ts := time.Now().UTC().Add(-30 * time.Hour).Format(time.RFC3339) + if err := st.SaveHostReport("h1", "c1", []byte(`{"pbs_snapshots":[{"backup_time":"`+ts+`","verify_state":"ok"}],"backups":[]}`), store.HostReportDenorm{}); err != nil { + t.Fatal(err) + } + if got := deadlineEvents(st, sc); got["expected_dbdump_missed"] != 0 || got["expected_backup_missed"] != 0 { + t.Fatalf("events %v — a dump 20 h ago and a backup 30 h ago are inside the down box's lines", got) + } +} + +// A new box (first report a day ago) that is down → nothing expected yet. +func TestR872_NewDownBoxIsQuiet(t *testing.T) { + st, _, sc := downBox(t, 24*time.Hour) + if got := deadlineEvents(st, sc); len(got) != 0 { + t.Fatalf("events %v for a box bound a day ago", got) + } +} diff --git a/hub/internal/notify/dispatcher.go b/hub/internal/notify/dispatcher.go index cdb49fa9..9c24c91c 100644 --- a/hub/internal/notify/dispatcher.go +++ b/hub/internal/notify/dispatcher.go @@ -758,6 +758,15 @@ var operatorOnlyEvents = map[string]bool{ // Read-only: the register itself stays unexported so nothing can widen it at runtime. func IsOperatorOnly(eventType string) bool { return operatorOnlyEvents[eventType] } +// householdLivenessTypes are the "your server cannot be reached" family; householdLivenessQuiet is how long after +// one reached the household the next is held back (R-873). +var ( + householdLivenessTypes = []string{"node_stale", "node_down", "host_stale", "host_down"} + householdLivenessWeekly = map[string]bool{"node_stale": true, "node_down": true, "host_stale": true, "host_down": true} +) + +const householdLivenessQuiet = 7 * 24 * time.Hour + func (d *Dispatcher) processCustomer(customerID, eventType, severity, message, messageCustomer, detailsJSON, source string) { // R-97c: operator-tier events stop here, BEFORE prefs are consulted — the point is that no // customer configuration can opt in. Logged rather than dropped, so the skip is visible in @@ -785,6 +794,22 @@ func (d *Dispatcher) processCustomer(customerID, eventType, severity, message, m return } + // R-873 (v0.134.0): "your server cannot be reached" reaches the HOUSEHOLD at most once per 7 days. A box that + // is switched off every night (Tester 2, a laptop — measured 2026-10-05) mailed the household every night and + // "reachable again" every morning. The operator still gets every edge (processOperator, above), and the + // recovery mail stays paired with a down mail the household actually received (processRecovery), so a skipped + // down mail also skips its recovery. Persisted (notification_log), so a hub restart does not reset it. + // Decided by CC — operator may reverse (`08` §3.1). Pinned by TestR873_*. + if householdLivenessWeekly[eventType] { + if last, ok, err := d.store.LastCustomerSentAt(customerID, householdLivenessTypes); err == nil && ok && time.Since(last) < householdLivenessQuiet { + d.store.LogNotification(customerID, eventType, severity, message, "skipped", + "liveness: the household hears this at most once per 7 days (R-873)", "customer") + d.logger.Printf("[INFO] Customer mail skipped for %s/%s — the household was told about an outage %s ago (R-873: at most once per 7 days)", + customerID, eventType, time.Since(last).Round(time.Minute)) + return + } + } + // Customer cooldown (from prefs, default 6h) cooldownHours := prefs.CooldownHours if cooldownHours <= 0 { diff --git a/hub/internal/notify/r873_liveness_weekly_test.go b/hub/internal/notify/r873_liveness_weekly_test.go new file mode 100644 index 00000000..86816f3e --- /dev/null +++ b/hub/internal/notify/r873_liveness_weekly_test.go @@ -0,0 +1,55 @@ +package notify + +import ( + "database/sql" + "io" + "log" + "path/filepath" + "testing" + "time" + + "gitea.dooplex.hu/admin/felhom-hub/internal/store" +) + +// R-873 (v0.134.0) — a household whose box is OFF EVERY NIGHT (Tester 2, a laptop) is told "your server cannot be +// reached" at most once per 7 days; the operator still hears every edge; the recovery mail stays paired. +// COMPANION RED-PROOF: drop the householdLivenessWeekly block in processCustomer → night 2 mails the household. +func TestR873_HouseholdHearsAnOutageAtMostWeekly(t *testing.T) { + path := filepath.Join(t.TempDir(), "d.db") + st, err := store.New(path, log.New(io.Discard, "", 0)) + if err != nil { + t.Fatal(err) + } + defer st.Close() + st.SaveCustomerConfig(&store.CustomerConfig{CustomerID: "c1", APIKey: "k", RetrievalPassword: "p"}) + if err := st.SaveNotificationPrefs("c1", "cust@example.com", []string{"node_down"}, 6); err != nil { + t.Fatal(err) + } + night := func() (cust, op int) { + // a fresh dispatcher each night: the in-memory 6 h cooldown is gone by the next evening anyway + d := NewDispatcher(st, "test-key", "from@felhom.eu", "op@felhom.eu", true, log.New(io.Discard, "", 0)) + sent := captureSeam(d) + d.ProcessEvent("c1", "node_down", "error", "No report received for 90m", "{}", "hub") + d.ProcessEvent("c1", "node_recovered", "info", "Reports resumed", "{}", "hub") + return len(mailsFor(*sent, "cust@example.com")), len(mailsFor(*sent, "op@felhom.eu")) + } + if c, o := night(); c != 2 || o != 2 { + t.Fatalf("night 1: household %d mails, operator %d — want down+recovered to both", c, o) + } + if c, o := night(); c != 0 || o != 2 { + t.Fatalf("night 2: household %d mails (want 0 — told once this week), operator %d (want every edge)", c, o) + } + // Eight days later the household is told again. + db, err := sql.Open("sqlite", path) + if err != nil { + t.Fatal(err) + } + defer db.Close() + old := time.Now().UTC().Add(-8 * 24 * time.Hour).Format("2006-01-02 15:04:05") + if _, err := db.Exec(`UPDATE notification_log SET created_at = ?`, old); err != nil { + t.Fatal(err) + } + if c, _ := night(); c != 2 { + t.Fatalf("after 8 days the household got %d mails, want down+recovered again", c) + } +}