From 50eeccc986a674a243a4f6a0e311274066b7fc45 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Mon, 2 Nov 2026 23:16:10 +0100 Subject: [PATCH] R-1302: the first grant of a tier logs INFO granted; a grant that existed and vanished keeps the R-190 ERROR. Commit only. --- CHANGELOG.md | 11 +++ cmd/felhom-agent/main.go | 85 ++++++++++++++++++++++- cmd/felhom-agent/storegrant_test.go | 101 ++++++++++++++++++++++++++++ 3 files changed, 194 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 66251a3..43a1cdd 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,14 @@ +## Unreleased — next agent release (needs the operator's vouch); commit only, 2026-11-02 night + +- **R-1302 — the first grant of a tier is no loss.** A fresh install arms the whole-guest tier before its storage exists, so the + first probe found no grant, repaired it and logged ERROR „GRANT WAS MISSING … investigate the loss (R-190)" plus a DEGRADED + capability, on every new box (VM 9375, 2026-10-26). The agent now remembers which tiers have EVER held their grant + (`/store-grant-seen.json`, written by a healthy probe). A first grant logs INFO „granted" and reports healthy; a + grant that existed and vanished keeps R-190's ERROR and its one degraded cycle. A doubt keeps the ERROR: an unreadable or + corrupt file, or no file path. A box updated to this agent records its tiers at the first healthy probe, so a loss in the + one probe before that would read as a first grant. Tests `TestR1302_*`; red seen with the first-grant branch removed and on + three more mutants. + ## v0.171.0 (2026-10-30) — R-1344 decided from the night's measurement: a controller that runs but does not answer is RESTARTED — RELEASED (release-agent.sh from a clean clone of `bd18347`; agent sha256 c888ca7ba22a1f689059081575814a725e2edcecbb6bcc56829e9d9de88202a5, config bundle 95f977f6dc827185f2b5a2aa9e1c829db41a9f425d49eb40f317286d13c83d2b; binary-only signed agent_update on Tester 1, demo-hp, demo-felhom; vouched by the operator 2026-10-30 10:47:36 CET; `pinned.day0_agent` = 0.171.0). Live on Tester 1: the controller frozen (SIGSTOP) 09:24:50 UTC → Docker „unhealthy" 09:26:36 → the alarm 09:29:21 → the restart 09:31:22 → healthy 09:31:24; the hub mailed `controller_unresponsive` and `controller_unresponsive_restart` (hub 0.178.0), not `controller_restarted_by_agent` - **The measurement (operator brief 2026-10-29 Part 2, read 2026-10-30).** Docker's own health record of the controller diff --git a/cmd/felhom-agent/main.go b/cmd/felhom-agent/main.go index d5254be..1688416 100644 --- a/cmd/felhom-agent/main.go +++ b/cmd/felhom-agent/main.go @@ -521,6 +521,66 @@ type storeGrantRepairer struct { mu sync.Mutex last map[string]time.Time // target id → last ATTEMPT (success or failure) repaired map[string]time.Time // target id → last CONFIRMED repair (drives the report latch) + // seenPath (R-1302) is the file that remembers which tiers have EVER held the grant: only those can LOSE it. "" = no + // memory, so every missing grant reads as a loss — the old, loud behaviour. + seenPath string +} + +// everHeld reports whether this tier's grant was ever seen on this box (R-1302). The direction of a doubt is „yes": an +// unreadable or corrupt file keeps the loss ERROR, so a real loss is never quietened by a broken record. +func (r *storeGrantRepairer) everHeld(target string) bool { + if r == nil || r.seenPath == "" { + return true + } + r.mu.Lock() + defer r.mu.Unlock() + seen, err := readGrantSeen(r.seenPath) + return err != nil || seen[target] +} + +// noteHeld records that this tier holds the grant. A write that fails is logged and costs one false „first grant" at most +// after a restart — the old file, or none, stands. +func (r *storeGrantRepairer) noteHeld(target string) { + if r == nil || r.seenPath == "" { + return + } + r.mu.Lock() + defer r.mu.Unlock() + seen, err := readGrantSeen(r.seenPath) + if err != nil { + seen = map[string]bool{} // a corrupt file is replaced by what is true now + } + if seen[target] { + return + } + seen[target] = true + b, _ := json.Marshal(seen) + tmp := r.seenPath + ".tmp" + if werr := os.WriteFile(tmp, b, 0o600); werr == nil { + werr = os.Rename(tmp, r.seenPath) + if werr == nil { + return + } + err = werr + } else { + err = werr + } + repairLogger(r).Warn("store-grant: could not record that this tier holds its grant (R-1302)", "target", target, "err", err) +} + +func readGrantSeen(path string) (map[string]bool, error) { + b, err := os.ReadFile(path) + if os.IsNotExist(err) { + return map[string]bool{}, nil + } + if err != nil { + return nil, err + } + seen := map[string]bool{} + if err := json.Unmarshal(b, &seen); err != nil { + return nil, err + } + return seen, nil } // noteRepaired latches a confirmed repair so it is reported for storeGrantRepairReportWindow. @@ -631,6 +691,7 @@ func storeGrantStatus(ctx context.Context, px *proxmox.Client, targetID string, // host-report has certainly carried it. Without this latch the repairing probe may be a // log-only one and the hub never learns anything happened (measured live, see the window's // comment). + repair.noteHeld(targetID) // R-1302: a tier that holds its grant can lose it from now on return storeGrantHealthyVerdict(targetID, critical, s, repair.recentlyRepaired(targetID, time.Now())) } @@ -679,8 +740,25 @@ func storeGrantStatus(ctx context.Context, px *proxmox.Client, targetID string, // produces exactly one alert pair and the operator learns of it. NOTHING NEW WAS BUILT: no wire // change, no hub change, no new event type. The `Feature` text carries the explanation because // that is the field the hub puts in the operator's e-mail (the Reason does not travel). + return storeGrantAfterRepair(targetID, critical, repair, s) +} + +// storeGrantAfterRepair is the verdict once a repair is confirmed (split out for the tests). R-1302: the FIRST grant of a +// tier that never held one is no loss — on a fresh install the whole-guest tier is armed before its storage exists, so +// every new box logged „investigate the loss" and a DEGRADED capability at its first start, which teaches the reader to +// skip the line. That grant logs INFO and reports healthy. A tier seen holding its grant, or one this box cannot tell +// about, keeps R-190's ERROR and its one degraded cycle. Pinned by TestR1302_*. +func storeGrantAfterRepair(targetID string, critical bool, repair *storeGrantRepairer, healthy capability.Status) capability.Status { + if !repair.everHeld(targetID) { + repair.noteHeld(targetID) + repairLogger(repair).Info("store-grant: granted — the first grant of this tier, nothing was lost (R-1302)", + "target", targetID, "privilege", storeGrantRequiredPriv, + "action", "felhom-backup-target-apply grant "+targetID, "confirmed_by", "re-read") + healthy.Status, healthy.Reason = capability.StatusOK, "" + return healthy + } repair.noteRepaired(targetID, time.Now()) - s = storeGrantRepairedVerdict(targetID, critical) + s := storeGrantRepairedVerdict(targetID, critical) repairLogger(repair).Error("store-grant: GRANT WAS MISSING AND HAS BEEN SELF-REPAIRED — investigate the loss (R-190)", "target", targetID, "privilege", storeGrantRequiredPriv, "action", "felhom-backup-target-apply grant "+targetID, "confirmed_by", "re-read") @@ -853,8 +931,9 @@ func runDaemon(cfg config.Config, logger *slog.Logger, logRing *applog.Ring) int // The runner is the DIRECT one for the same reason the sudo prober uses it: the wrapper is // invoked through the privileged path, which prepends sudo itself. grantRepairer := &storeGrantRepairer{ - run: (&proxmox.ExecRunner{Mode: proxmox.RunnerMode(cfg.Privileged.Mode)}).Run, - log: logger, + run: (&proxmox.ExecRunner{Mode: proxmox.RunnerMode(cfg.Privileged.Mode)}).Run, + log: logger, + seenPath: filepath.Join(agentStateDir(cfg), "store-grant-seen.json"), // R-1302 } // R-973: the local-API backup cadence cap's refusals ride the report as a CRITICAL status, so the hub's // operator-only whole_guest_backup_refused event (hub v0.159.0, R-1150) tells the operator. Late-bound like diff --git a/cmd/felhom-agent/storegrant_test.go b/cmd/felhom-agent/storegrant_test.go index cf6e0f5..b534a3a 100644 --- a/cmd/felhom-agent/storegrant_test.go +++ b/cmd/felhom-agent/storegrant_test.go @@ -1,11 +1,14 @@ package main import ( + "bytes" "context" "errors" "go/ast" "io" "log/slog" + "os" + "path/filepath" "strings" "testing" "time" @@ -415,3 +418,101 @@ func TestGrantRepair_TransitionSurvivesALaterProbe(t *testing.T) { "be missed entirely", storeGrantRepairReportWindow) } } + +// ── R-1302 — the first grant of a tier is no loss ────────────────────────────────────── +// +// A fresh install arms the whole-guest tier before its storage exists, so its first probe found no grant, repaired it and +// logged „GRANT WAS MISSING … investigate the loss" with a DEGRADED capability — on every new box (VM 9375, 2026-10-26). +// +// RED-PROOF (2026-11-02): seen failing before storeGrantAfterRepair existed (build), and with its first-grant branch removed +// TestR1302_TheFirstGrantIsNoLoss fails on „a first grant must not report a loss". +func r1302Repairer(t *testing.T, path string) (*storeGrantRepairer, *bytes.Buffer) { + t.Helper() + var buf bytes.Buffer + return &storeGrantRepairer{run: (&fakeRepairRunner{}).Run, seenPath: path, + log: slog.New(slog.NewTextHandler(&buf, nil))}, &buf +} + +func TestR1302_TheFirstGrantIsNoLoss(t *testing.T) { + path := filepath.Join(t.TempDir(), "store-grant-seen.json") + r, buf := r1302Repairer(t, path) + healthy := capability.Status{Name: "pve:store-grant:felhom-pbs", Status: capability.StatusDegraded, Reason: "missing", Critical: true} + s := storeGrantAfterRepair("felhom-pbs", true, r, healthy) + if s.Status != capability.StatusOK || s.Reason != "" { + t.Fatalf("a first grant must not report a loss: status %q reason %q", s.Status, s.Reason) + } + got := buf.String() + if strings.Contains(got, "investigate the loss") || strings.Contains(got, "level=ERROR") { + t.Fatalf("a first grant must not log the loss ERROR: %s", got) + } + if !strings.Contains(got, "level=INFO") || !strings.Contains(got, "granted") || !strings.Contains(got, "felhom-pbs") { + t.Fatalf("a first grant says so at INFO: %s", got) + } + if r.recentlyRepaired("felhom-pbs", time.Now()) { + t.Fatal("a first grant must not arm the loss report's latch") + } +} + +func TestR1302_AGrantThatExistedAndVanishedKeepsTheError(t *testing.T) { + path := filepath.Join(t.TempDir(), "store-grant-seen.json") + first, _ := r1302Repairer(t, path) + first.noteHeld("felhom-pbs") // a healthy probe, in an earlier run of the agent + + r, buf := r1302Repairer(t, path) // the agent restarted: the memory is the file, not the process + s := storeGrantAfterRepair("felhom-pbs", true, r, capability.Status{}) + if s.Status != capability.StatusDegraded || !strings.Contains(s.Feature, "R-190") { + t.Fatalf("a grant that existed and vanished must keep its degraded cycle; got %q / %q", s.Status, s.Feature) + } + if got := buf.String(); !strings.Contains(got, "level=ERROR") || !strings.Contains(got, "investigate the loss") { + t.Fatalf("a grant that existed and vanished must keep its ERROR: %s", got) + } + if !r.recentlyRepaired("felhom-pbs", time.Now()) { + t.Fatal("the loss must arm the report's latch, or the hub may never hear it") + } +} + +// After a first grant the tier counts as held: the NEXT disappearance is a loss. +func TestR1302_AfterTheFirstGrantALossIsALoss(t *testing.T) { + path := filepath.Join(t.TempDir(), "store-grant-seen.json") + r, _ := r1302Repairer(t, path) + storeGrantAfterRepair("felhom-pbs", true, r, capability.Status{}) + s := storeGrantAfterRepair("felhom-pbs", true, r, capability.Status{}) + if s.Status != capability.StatusDegraded { + t.Fatalf("the second disappearance is a loss; got %q", s.Status) + } +} + +// The direction of a doubt: a broken record, a repairer with no record, or no repairer at all keep the loud way. +func TestR1302_ADoubtKeepsTheError(t *testing.T) { + path := filepath.Join(t.TempDir(), "store-grant-seen.json") + if err := os.WriteFile(path, []byte("{not json"), 0o600); err != nil { + t.Fatal(err) + } + r, _ := r1302Repairer(t, path) + if s := storeGrantAfterRepair("felhom-pbs", true, r, capability.Status{}); s.Status != capability.StatusDegraded { + t.Fatalf("a corrupt record must not quieten a loss; got %q", s.Status) + } + noMemory, _ := r1302Repairer(t, "") + if s := storeGrantAfterRepair("felhom-pbs", true, noMemory, capability.Status{}); s.Status != capability.StatusDegraded { + t.Fatalf("no record must not quieten a loss; got %q", s.Status) + } + if s := storeGrantAfterRepair("felhom-pbs", true, nil, capability.Status{}); s.Status != capability.StatusDegraded { + t.Fatalf("no repairer must not quieten a loss; got %q", s.Status) + } +} + +// The wiring, read from the source: production names the file, and a healthy probe records the tier. +func TestR1302_TheMemoryIsWired(t *testing.T) { + b, err := os.ReadFile("main.go") + if err != nil { + t.Fatal(err) + } + src := string(b) + if !strings.Contains(src, `seenPath: filepath.Join(agentStateDir(cfg), "store-grant-seen.json")`) { + t.Fatal("main.go must give the repairer its file, or every first grant reads as a loss") + } + start := strings.Index(src, "func storeGrantStatus(") + if start < 0 || !strings.Contains(src[start:start+3000], "repair.noteHeld(targetID)") { + t.Fatal("a healthy probe must record the tier, or a real loss would read as a first grant") + } +}