Files
felhom.eu/hub/internal/monitor/deadline.go
T
admin b03a105375
gates / gates (push) Successful in 17s
hub v0.105.0: the third name, a machine told to be quiet, and a guard for the hub's own words
Hub only. No controller change, no agent change, no wire change — nothing to bake.
demo-hp untouched: the operator is re-deploying it this evening.

R-323 — the five-word phrase is „Tulajdonosi jelmondat". It was „Visszaállító
jelszó": one word from the name retired last week, and false besides — it restores
nothing, it proves the account owns the box being bound. Five sites, all in the hub;
felhom-controller and felhom-agent carry the name nowhere, so no halt and no bake.
Both suggested names were rejected with reasons: „Fiókjelszó" would collide with the
dashboard login (a DIFFERENT real secret), and „Összekötési jelszó" would leave the
two factors on this page separated only by kód-versus-jelszó — the exact shape being
removed, since the other factor is the „Párosító kód". The chosen name differs on
both axes, stem and noun. Naming only; the acceptance pin drives the real handler.

R-324 — the hub's customer copy is under a guard for the first time. Retired names
banned across all 95 hub files; retrieval stems registered in four declared customer
surfaces. The selftest found a defect in its own instrument on the first run. One
shared vocabulary in scripts/, drift-checked into the controller gate rather than
copied (R-325 removes the scaffold).

R-321 — a machine we told to be quiet is no longer reported as dead, and it was two
doors, not one: because the state is RECORDED rather than deleted, the morning
deadline check can skip it too. A deleted state returns "", which is not "down" —
R-195's shape returning through a second door. The clock runs from the report the hub
can see, so re-enabling starts it there and emits no recovery for an outage that never
happened. Three red-proofs; the one that matters showed a genuinely dead machine
sitting at "disabled" when the suppression was made unconditional.

R-326 — "which claims are unproven" is answerable by a command now. The nine I have
been repeating was the count of claims the 9 August pass DOWNGRADED, not the count of
unproven ones. The real figures: 55 claims, 23 walked, 32 not — and only 6 of those 32
cite evidence. Its first run found a stale claim (R-327).
2026-08-13 15:50:32 +02:00

477 lines
22 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package monitor
import (
"encoding/json"
"fmt"
"log"
"strings"
"time"
"gitea.dooplex.hu/admin/felhom-hub/internal/store"
)
// backupStaleAfter is the maximum age of the newest offsite backup before the daily
// deadline check raises expected_backup_missed. 26h covers an evening backup schedule
// (e.g. ~18:0022:00) plus headroom, so a healthy once-daily cadence never trips the
// early-morning check.
//
// R-81 also reuses it as the ABSENCE window (see assessBackupFreshness): the existing
// threshold, anchored at first-contact, IS the newborn grace — no new knob, exactly as
// v0.73.0 reused offsite staleAfter for its never-ran anchor.
//
// ⚠️ LANDMINE — dependency on R-82 (the backup target split). This constant is applied to
// whichever tier is NEWEST, PBS or vzdump, with no tier-awareness. Today a daily vzdump
// always wins, so PBS's own age is invisible here and 26h is harmless. The moment PBS moves
// to a WEEKLY cadence, a perfectly healthy weekly snapshot is >26h old six days in seven and
// this constant alarms on it. Fixing that means per-tier thresholds, which cannot be built
// before the per-tier cadence config exists (`local_backup_target` is a single target and
// BackupCadence() a single 24h window today). Do NOT pre-build it — R-82 owns both halves.
const backupStaleAfter = 26 * time.Hour
// backupEvidenceLookback bounds how far back the hub looks for evidence that a backup ever
// happened, when the LATEST report carries none. Generous against any plausible daily cadence
// (and against an agent that stayed restarted for days), bounded so the cold path can't turn
// into a full-retention scan of every report the hub holds. Beyond this the verdict is
// "no evidence in the lookback", which is a fault in its own right once the anchor elapsed.
const backupEvidenceLookback = 7 * 24 * time.Hour
// hostReportBackups is the minimal slice of an agent host-report the deadline check
// reads to judge backup freshness (pbs_snapshots is the offsite-DR signal; backups is
// the local vzdump fallback). Mirrors the agent's hub.PBSSnapshot / hub.Backup wire
// contract for just the fields we need.
type hostReportBackups struct {
PBSSnapshots []struct {
BackupTime string `json:"backup_time"`
VerifyState string `json:"verify_state"`
} `json:"pbs_snapshots"`
Backups []struct {
// TargetID is the SLICE-C discriminator: a backups[] entry belongs to whichever tier its
// target storage belongs to, never to "the local tier" by virtue of being in this array.
TargetID string `json:"target_id"`
StartedAt string `json:"started_at"`
Success bool `json:"success"`
} `json:"backups"`
// StorageTargets carries the target TYPE, which is how a backups[] entry is attributed to a
// tier (target_id → name → type == "pbs"). See pbsTargetSet.
StorageTargets []struct {
Name string `json:"name"`
Type string `json:"type"`
Content string `json:"content"`
} `json:"storage_targets"`
}
// backupVerdict is the three-valued outcome of the freshness policy. The middle value is the
// whole point of R-81: "I have no evidence" is NOT "the backup failed".
type backupVerdict int
const (
verdictOK backupVerdict = iota // positive evidence of a recent backup
verdictUnknown // no evidence yet, and the anchored window has not elapsed
verdictMissed // positive evidence of a problem — alarm
)
// backupAssessment is the verdict for one customer's offsite backup health.
type backupAssessment struct {
verdict backupVerdict
reason string // human-readable cause (event message + logs)
}
// missed reports whether this assessment should raise expected_backup_missed.
func (a backupAssessment) missed() bool { return a.verdict == verdictMissed }
// backupEvidence is the hub-history half of the freshness policy, resolved by the caller so
// assessBackupFreshness stays PURE (see its doc comment on why that matters).
type backupEvidence struct {
// newestSeen is the newest backup evidence found across the retained host-report window
// (PBS backup_time or successful vzdump started_at), regardless of whether the LATEST
// report still carries it. haveSeen is false when the window held none.
newestSeen time.Time
haveSeen bool
// Per-tier window evidence (R-82 Slice C). A single "newest across everything" would let a
// fresh daily host backup satisfy the OFFSITE tier's lookup — the same error Slice A fixed
// agent-side. newestSeen/haveSeen above remain the pre-Slice-C combined values, used only by
// the no-tier fallback path.
newestHost time.Time
haveHost bool
newestOffsite time.Time
haveOffsite bool
// firstReportAt is when the hub first saw ANY host-report from this customer — the
// observation anchor. Zero when unknown, which the policy treats as "cannot defer"
// (fail toward visibility, matching the v0.73.0 zero-anchor branch).
firstReportAt time.Time
}
// assessBackupFreshness decides whether a customer's backups are healthy. Pure (now and the
// hub-history evidence are injected) so the policy is unit-tested — that purity is why the
// 2026-07-26 incident could be diagnosed at all, and why the fix below is provable.
//
// ── THE INVARIANT (R-81) ──────────────────────────────────────────────────────────────────
//
// Only POSITIVE EVIDENCE OF A PROBLEM raises an alarm. ABSENCE OF A SIGNAL IS UNKNOWN,
// and becomes a fault only once that absence has persisted beyond an ANCHORED window.
//
// This monitor family has made the same mistake three times, and it is written down here so
// the fourth is harder:
// - hub v0.12.0 — `expected_backup_missed` fired daily for every healthy customer, because
// it looked for a `backup_completed` event that no component emits anymore.
// - hub v0.73.0 — `offsite_stale` fired minutes after a HEALTHY repair, because the
// never-ran branch had no time anchor. Fixed by anchoring, not by silence.
// - R-81 (this) — `expected_backup_missed` fired on three boxes at once on 2026-07-26,
// because an agent restart empties the host-report `backups` array (the agent's store is
// in-memory) and empty was read as "no backup exists". The vzdump had in fact run.
//
// Note the shape of the fix in all three: NOT silence. Silence is the opposite failure — a
// box that genuinely never backs up would then alarm never, which is strictly worse than
// crying wolf. Absence is deferred, then alarmed on, with its own distinct reason string.
//
// ── THE BRANCHES ──────────────────────────────────────────────────────────────────────────
//
// unparseable latest report → missed ("could not be parsed")
// newest evidence (report OR window) older than staleAfter → missed ("newest backup is Xh old")
// newest PBS snapshot's verify_state == "failed" → missed ("failed verification")
// NO evidence anywhere, anchor NOT yet elapsed → UNKNOWN, silent + logged
// NO evidence anywhere, anchor elapsed → missed ("no backup evidence in …")
// otherwise → ok
//
// Each failure mode keeps its OWN reason string. That is not polish: the entire 2026-07-26
// diagnosis turned on reading the exact string, and collapsing them would have made it
// impossible. In particular "absence over time" and "a timestamp that is too old" are
// different faults with different causes, and must never share a message.
//
// A fresh-but-not-yet-verified snapshot (verify_state "none"/"") is NOT treated as a
// failure: PBS verification runs on its own cadence, so a snapshot taken hours before the
// 03:00 check may legitimately be unverified. Alarming on that would re-introduce exactly
// the daily false alarm the v0.12.0 repoint removed (hence "failed" only, not "≠ ok").
func assessBackupFreshness(reportJSON string, ev backupEvidence, now time.Time) backupAssessment {
var hr hostReportBackups
if err := json.Unmarshal([]byte(reportJSON), &hr); err != nil {
// Unparseable report → can't confirm a backup. Surface it rather than swallow it.
return backupAssessment{verdict: verdictMissed, reason: "latest host-report could not be parsed"}
}
var newestPBS time.Time
var newestPBSVerify string
havePBS := false
for _, ps := range hr.PBSSnapshots {
t, ok := parseBackupTime(ps.BackupTime)
if !ok {
continue
}
if !havePBS || t.After(newestPBS) {
havePBS = true
newestPBS = t
newestPBSVerify = strings.ToLower(strings.TrimSpace(ps.VerifyState))
}
}
var newestVzdump time.Time
haveVzdump := false
for _, b := range hr.Backups {
if !b.Success {
continue
}
t, ok := parseBackupTime(b.StartedAt)
if !ok {
continue
}
if !haveVzdump || t.After(newestVzdump) {
haveVzdump = true
newestVzdump = t
}
}
// ── R-82 Slice C: TIER-AWARE assessment ───────────────────────────────────────────────────
// Judge each tier against ITS OWN threshold. Falls through to the pre-Slice-C combined logic
// below only when NEITHER tier is identifiable — an old agent whose report carries no
// storage_targets and no target_id — so nothing regresses on a fleet mid-upgrade.
hostView, offView := splitTiers(hr)
if hostView.expected || offView.expected {
var as []backupAssessment
if hostView.expected {
as = append(as, assessTier(tierHost, hostView, ev.newestHost, ev.haveHost, ev.firstReportAt, now))
}
if offView.expected {
as = append(as, assessTier(tierOffsite, offView, ev.newestOffsite, ev.haveOffsite, ev.firstReportAt, now))
}
return worst(as...)
}
// The newest evidence the LATEST report itself carries.
newest := newestPBS
haveNewest := havePBS
if haveVzdump && (!haveNewest || newestVzdump.After(newest)) {
newest, haveNewest = newestVzdump, true
}
// R-81: fold in what the hub REMEMBERS. The agent's store is point-in-time and forgets
// across a restart; the hub's retained host-reports do not. An empty array in the latest
// report therefore says nothing on its own — the question is when evidence was last SEEN,
// not whether this one report happens to carry it.
if ev.haveSeen && (!haveNewest || ev.newestSeen.After(newest)) {
newest, haveNewest = ev.newestSeen, true
}
if !haveNewest {
// ABSENCE. Not a failure by itself — see the invariant above. It becomes one only
// once it has outlived the existing threshold, counted from first contact (the point
// at which a backup first became possible to observe).
if ev.firstReportAt.IsZero() {
// No anchor to defer against — fail toward visibility, as v0.73.0 does for the
// legacy zero-anchor shape. Distinct string: this is an unanchored absence.
return backupAssessment{
verdict: verdictMissed,
reason: "no backup evidence in any retained host-report, and no first-contact anchor to defer against",
}
}
watched := now.Sub(ev.firstReportAt)
if watched <= backupStaleAfter {
return backupAssessment{
verdict: verdictUnknown,
reason: fmt.Sprintf("no backup evidence yet, but only watching for %s (grace %s since first contact %s) — newborn host, not a fault",
watched.Round(time.Hour), backupStaleAfter, ev.firstReportAt.Format(time.RFC3339)),
}
}
return backupAssessment{
verdict: verdictMissed,
reason: fmt.Sprintf("no backup evidence in any host-report for %s (limit %s, first contact %s, lookback %s)",
watched.Round(time.Hour), backupStaleAfter, ev.firstReportAt.Format(time.RFC3339), backupEvidenceLookback),
}
}
if age := now.Sub(newest); age > backupStaleAfter {
return backupAssessment{verdict: verdictMissed, reason: fmt.Sprintf("newest backup is %s old (limit %s)", age.Round(time.Hour), backupStaleAfter)}
}
if havePBS && newestPBSVerify == "failed" {
return backupAssessment{verdict: verdictMissed, reason: "newest PBS snapshot failed verification"}
}
return backupAssessment{verdict: verdictOK}
}
// newestBackupEvidence scans the customer's retained host-reports (newest first) for the most
// recent backup evidence — a PBS snapshot backup_time or a SUCCESSFUL vzdump started_at —
// regardless of whether the latest report still carries it.
//
// Cost discipline: it stops as soon as it has found evidence FRESH enough that nothing older
// could change the verdict, so the healthy path reads one row. Only the genuinely-broken path
// (no fresh evidence anywhere) walks the full lookback, and that is bounded by
// backupEvidenceLookback rather than by retention.
func newestBackupEvidence(rows []store.HostReportRow, now time.Time) (time.Time, bool) {
var newest time.Time
have := false
for _, r := range rows {
var hr hostReportBackups
if err := json.Unmarshal([]byte(r.ReportJSON), &hr); err != nil {
continue // a single malformed retained report must not blind the scan
}
for _, ps := range hr.PBSSnapshots {
if t, ok := parseBackupTime(ps.BackupTime); ok && (!have || t.After(newest)) {
newest, have = t, true
}
}
for _, b := range hr.Backups {
if !b.Success {
continue
}
if t, ok := parseBackupTime(b.StartedAt); ok && (!have || t.After(newest)) {
newest, have = t, true
}
}
// Fresh evidence found → the age branch cannot fire and nothing older matters.
if have && now.Sub(newest) <= backupStaleAfter {
break
}
}
return newest, have
}
// parseBackupTime parses an RFC3339 timestamp from a host-report and normalizes to UTC.
func parseBackupTime(s string) (time.Time, bool) {
s = strings.TrimSpace(s)
if s == "" {
return time.Time{}, false
}
if t, err := time.Parse(time.RFC3339, s); err == nil {
return t.UTC(), true
}
return time.Time{}, false
}
// budapest returns the Europe/Budapest timezone (cached).
var budapest *time.Location
func init() {
var err error
budapest, err = time.LoadLocation("Europe/Budapest")
if err != nil {
// Fallback: UTC+1 (CET base; DST handled by OS if available)
budapest = time.FixedZone("CET", 3600)
}
}
// CheckBackupDeadlines checks whether active customers had their expected
// daily backups and DB dumps. Runs once daily (early morning, Budapest time).
//
// Backup half: read the agent's latest host-report and raise expected_backup_missed
// only when its PBS snapshots / vzdump backups show no fresh, verified backup (see
// assessBackupFreshness). This replaced the old backup_completed-event check, which
// fired daily for every healthy customer because no component emits that event anymore
// (the controller's disk-tier backup moved to the agent in slice 8C).
//
// DB-dump half: unchanged — the in-guest controller still emits db_dump_completed, so
// the event-based check there is correct.
//
// Customers whose nodes are "down" (no report in >1h) are skipped — they
// already have staleness events.
// stalenessState reads a customer's staleness state, tolerating a nil checker. Named rather than
// inlined so the two states this function skips on are visible in one place — a second caller adding
// a third state must not have to rediscover that the nil check exists.
func stalenessState(staleness *StalenessChecker, customerID string) string {
if staleness == nil {
return ""
}
return staleness.GetState(customerID)
}
func CheckBackupDeadlines(s *store.Store, staleness *StalenessChecker, onEvent EventNotifyFunc, logger *log.Logger) {
customerIDs, err := s.GetActiveCustomerIDs()
if err != nil {
logger.Printf("[WARN] Deadline check: failed to get active customers: %v", err)
return
}
// Budapest midnight today
now := time.Now().In(budapest)
midnightBudapest := time.Date(now.Year(), now.Month(), now.Day(), 0, 0, 0, 0, budapest)
sinceUTC := midnightBudapest.UTC()
var backupMissed, dbdumpMissed, skipped, deferred, unbound int
for _, id := range customerIDs {
// Skip nodes that are down — they already have staleness events.
//
// R-321 adds StateDisabled to the same skip, and it is NOT cosmetic. This check is a second
// door onto the same false alarm: a box whose reporting we switched off deliberately is not
// "down" (the staleness checker suppresses that), so without this it would keep e-mailing
// `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 {
skipped++
continue
}
// Check blocked
if s.IsCustomerBlocked(id) {
continue
}
// ── R-195: a customer with NO machine EVER bound is UNKNOWN, not missed ────────────────
//
// Both verdicts below ask "did the thing we expect every day happen?". For a customer
// that has never had a machine bound, nothing has ever been expected, so the honest
// answer is UNKNOWN — the same invariant assessBackupFreshness states above, applied one
// level up, at the question of whether there is a subject at all.
//
// The discriminator is "was a host EVER bound", NOT "has a report arrived". That is the
// case this check must not break: a box that was installed, bound, and then went silent
// has a real fault and must keep alarming. It is bound, so it is judged.
//
// WHY THIS WAS REACHABLE AT ALL, measured 2026-08-04: the down-skip above is what
// protects every other silent customer, and it reads the staleness checker's state — which
// is seeded from the `reports` table (store.GetCustomers). A customer that has NEVER
// reported appears in no report row, so it gets no staleness state at all and GetState()
// returns "" rather than "down". The skip misses exactly the customer it would most
// obviously cover, and the DB-dump half below then fires every night: `david`, a
// prospective customer whose record was created 2026-08-01 with no machine ever bound,
// e-mailed an expected_dbdump_missed ERROR at 03:00 UTC on three consecutive days.
//
// Fail-open on a read error: an unreadable binding must never SUPPRESS a real alarm.
if bound, berr := s.HasEverBoundHost(id); berr != nil {
logger.Printf("[WARN] Deadline check: failed to read host binding for %s (judging anyway): %v", id, berr)
} else if !bound {
// Visible, per the v0.73.0 Part-7 precedent below: a quiet check must never be
// indistinguishable from a check that did not run. Once daily, one line per customer.
logger.Printf("[INFO] Deadline check: %s has no host EVER bound — all deadline verdicts UNKNOWN (no alarm)", id)
unbound++
continue
}
// Backup freshness from the agent's host-report (PBS snapshots + vzdump),
// the authoritative offsite-backup signal post-slice-8C.
reportJSON, rerr := s.GetLatestHostReportJSON(id)
switch {
case rerr != nil:
logger.Printf("[WARN] Deadline check: failed to read host-report for %s: %v", id, rerr)
case reportJSON == "":
// No agent host-report at all (legacy/defunct controller-only customer).
// Liveness is owned by the host-staleness checker; the backup deadline check
// has no PBS data to judge here and must not emit a daily backup alarm of its
// own. (The DB-dump half below still applies.)
default:
nowUTC := time.Now().UTC()
// R-81: resolve the hub-history half BEFORE judging. A read failure here must not
// invent a fault — it degrades to "the latest report is all I know", which is the
// pre-R-81 behaviour, and is logged rather than swallowed.
var ev backupEvidence
if rows, rerr := s.GetHostReportsSince(id, nowUTC.Add(-backupEvidenceLookback)); rerr != nil {
logger.Printf("[WARN] Deadline check: failed to read host-report window for %s: %v", id, rerr)
} else {
ev.newestSeen, ev.haveSeen = newestBackupEvidence(rows, nowUTC)
// Slice C: per-tier window evidence. Which tiers to look for comes from the LATEST
// report, so a box with no offsite tier never pays for scanning one.
var latest hostReportBackups
wantHost, wantOffsite := true, true
if json.Unmarshal([]byte(reportJSON), &latest) == nil {
h, o := splitTiers(latest)
wantHost, wantOffsite = h.expected, o.expected
}
ev.newestHost, ev.haveHost, ev.newestOffsite, ev.haveOffsite =
newestBackupEvidenceByTier(rows, wantHost, wantOffsite, nowUTC)
}
if first, ferr := s.GetFirstHostReportAt(id); ferr != nil {
logger.Printf("[WARN] Deadline check: failed to read first host-report for %s: %v", id, ferr)
} else {
ev.firstReportAt = first
}
a := assessBackupFreshness(reportJSON, ev, nowUTC)
switch a.verdict {
case verdictMissed:
msg := "No fresh verified backup: " + a.reason
if _, err := s.SaveEvent(id, "expected_backup_missed", "error", msg, "{}", "hub"); err != nil {
logger.Printf("[WARN] Failed to save expected_backup_missed for %s: %v", id, err)
} else if onEvent != nil {
onEvent(id, "expected_backup_missed", "error", msg, "{}", "hub")
}
backupMissed++
case verdictUnknown:
// Make the deferral VISIBLE (the v0.73.0 Part-7 precedent): a quiet check must
// never be indistinguishable from a check that did not run. This check fires
// once daily, so this is at most one line per customer per day — not spam, and
// it is the line that proves the deferral happened rather than an error.
logger.Printf("[INFO] Deadline check: %s backup verdict UNKNOWN (no alarm) — %s", id, a.reason)
deferred++
}
}
// Check db_dump_completed / db_dump_failed since midnight
dumpOK, _ := s.GetEventsByType(id, "db_dump_completed", sinceUTC)
dumpFailed, _ := s.GetEventsByType(id, "db_dump_failed", sinceUTC)
if len(dumpOK) == 0 && len(dumpFailed) == 0 {
msg := "No DB dump completed or failed since midnight"
if _, err := s.SaveEvent(id, "expected_dbdump_missed", "error", msg, "{}", "hub"); err != nil {
logger.Printf("[WARN] Failed to save expected_dbdump_missed for %s: %v", id, err)
} else if onEvent != nil {
onEvent(id, "expected_dbdump_missed", "error", msg, "{}", "hub")
}
dbdumpMissed++
}
}
logger.Printf("[INFO] Deadline check: %d customers, %d backup missed, %d backup unknown (deferred), %d dbdump missed, %d skipped (down), %d unknown (no host ever bound)",
len(customerIDs), backupMissed, deferred, dbdumpMissed, skipped, unbound)
}