REPORT: 2026-11-02 night, R-1302, commit only

CHANGELOG.md

@@ -1,4 +1,15 @@
-## Unreleased — R-1344 decided from the night's measurement: a controller that runs but does not answer is RESTARTED
+## 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
+  (`<state dir>/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
   on Tester 1 and demo-hp, every probe from 2026-10-29 11:12 to 2026-10-30 07:00 UTC: 4 733 probes through the night

CONTEXT.md

@@ -1,12 +1,22 @@
 # CONTEXT — felhom-agent working state
 
+> **2026-10-30 (day, attended) — v0.171.0 RELEASED and VOUCHED (10:47:36 CET): R-1344 decided — a controller that runs
+> but does not answer is RESTARTED.** The night's measurement (4 733 probes, slowest 303 ms, no failure) licensed it:
+> alarm at `controllerUnresponsiveConfirm` = 6 unhealthy sweeps, restart at `controllerUnresponsiveRestart` = 10 —
+> refused by a fresh/unreadable busy file (`controllerBusy`, shared with D65's reboot) or the brake
+> (`supervisorBrakeAllows`, now shared with the not-running restart; `recordSupervisorRestart` records both). The stanza
+> carries `unresponsive_restart_after_s` and `unresponsive_restart_at` (hub 0.178.0 mails
+> `controller_unresponsive_restart`). Built from `bd18347` (`c888ca7b…`, bundle `95f977f6…`), binary-only signed
+> updates on the three test boxes; live on Tester 1 (SIGSTOP → alarm 4.5 min → restart 6.5 min → healthy).
+> `pinned.day0_agent` = 0.171.0. felhom.eu `REPORT-release-2026-10-30.md`.
+
 > **2026-10-29 (evening, attended) — v0.170.0 RELEASED and VOUCHED (18:57:48 CET): `reboot_guest` (D65 = A).**
 > `da8d12a0…`, bundle `03f2ff64…`, tag `v0.170.0`, from a clean clone of `ca15a31`; configs/ changed (one new read-only
 > sudo vector: `cat` of the controller's `data/ctl/busy`), so per box a signed `agent_config_update` + `agent_update`
 > (Tester 1, demo-hp, demo-felhom; capability probe 76/76). The agent's closed list is `restart_controller` +
 > `reboot_guest` (`opreboot.go`; guards in felhom.eu `03`/`04` §6.1). Proven on Tester 1: refused during an off-site run
 > (the controller's busy file), done in 67 s / 79 s, refused a second time inside the hour. `pinned.day0_agent` = 0.170.0.
-> **R-1344 (the stuck-controller restart) is still ALARM ONLY** — the night's health log is read on 2026-10-30.
+> **R-1344 decided 2026-10-30: RESTART** (see the 2026-10-30 entry above).
 
 > **2026-10-29 (afternoon, attended) — v0.169.0 RELEASED and VOUCHED (14:06:09 CET).** `fc066de6…`, bundle `3ca33f9c…`,
 > from `637c92c`; `pinned.day0_agent` 0.169.0 (`db25eb0`). The agent's own closed operator-action list:

REPORT.md

@@ -1,36 +1,5 @@
-# REPORT — v0.170.0 released and vouched: „Reboot guest" from the hub (D65 = A, 2026-10-29 evening, attended)
+# REPORT — 2026-11-02 night: R-1302, commit only (no release)
 
-**Plain words first.** The operator can now reboot a box's guest from the hub's host page, beside „Restart controller".
-The agent does it (`pct reboot` of that guest — never the host). It refuses during a backup, a restore, an update or a
-controller swap, more than once an hour, and under the restart brake. The result says when the guest and the controller
-were back. The controller that starts after the reboot tells the household for a day that Felhom support restarted
-the box.
+**Plain words.** Nothing was released. A new box no longer logs „investigate the loss" for a grant it simply never had; a grant that existed and vanished still does.
 
-## Commits
-
-| Commit | CI (job id) | What |
-|---|---|---|
-| `ca15a31` | 2520, 2524 green | `reboot_guest` in the closed list (`opreboot.go`): guards (provisioned, running, not locked, not parked; the heavy-operation gate held until the guest is up; `jobBlocker`; the controller's busy file, fresh ≤ 90 s, fail closed on any read error but „no file"; one per hour per guest, persisted; the restart brake counts it); `rebootInFlight` keeps the guest-power watchdog and the supervisor away; the result with both times; `GET /guest/operator-reboot` for the household line; one new read-only sudo vector (`cat` of the controller's busy file) + capability `controller-busy-read`. 19 mutants, each killed (one survivor found and fixed: a duplicate swap check). |
-| `6578a8b` | 2525 green | v0.170.0 CHANGELOG heading; `pinned.day0_agent` = 0.170.0 (D50), after the vouch. |
-
-## Release
-
-- `release-agent.sh 0.170.0` from a clean clone of `ca15a31`: sha256 `da8d12a05ef607c338b9ba307e7a81b18253a3188721bbd8421ba36658a22404`,
-  bundle `03f2ff6442fc3ca600b1f25f26767ce4da466a770a258f3e362cf95f6e76b543`, tag `v0.170.0`, verified by download.
-- configs/ changed, so per box a signed `agent_config_update` AND `agent_update` (Tester 1, demo-hp, demo-felhom): all
-  six COMPLETED; each box „config bundle INSTALLED", capability probe 76/76 ok, „update committed".
-- Vouched by the operator 2026-10-29 18:57:48 CET (the save took 38.3 s — felhom.eu R-1346).
-
-## Live proofs (Tester 1, through the hub endpoint the button posts, CC's `cc-hosts` token; controller 0.349.0-rc.1)
-
-- **Refused during an off-site run:** `offsite_backup_now` pressed 18:03:36 UTC → the controller's busy file 11 s later →
-  „Reboot guest" → „refused: the controller is busy — a backup, a restore or an off-site run is running"; the guest kept
-  its 13 h uptime.
-- **The reboot:** pressed 18:05:08 UTC → „done — rebooted; the guest was up after 67 s, the controller answered after
-  79 s", on the hub 88 s after the press. Box walk after: 10 containers, none unhealthy, 0 errors, login and file manager
-  200. The household dashboard: „A Felhom ügyfélszolgálata 19:05-kor újraindította a dobozt."
-- **A second press inside the hour:** „refused: guest 9201 was rebooted from the hub at 18:05 UTC — at most one reboot
-  per hour (next from 19:05 UTC)".
-- The release-build reboot: see felhom.eu `REPORT-release-2026-10-29c.md`.
-
-Evidence: felhom.eu `documentation/audits/release-2026-10-29c/`.
+`50eeccc`, CI job 2552 green. `<state dir>/store-grant-seen.json` remembers which tiers held their grant; a first grant logs INFO and reports healthy; a doubt (no file path, an unreadable or corrupt file) keeps the ERROR. Tests `TestR1302_*` (`cmd/felhom-agent/storegrant_test.go`), seen failing before the code existed and on four mutants. Not seen live: it needs a release and the operator's vouch. A box updated to it records its tiers at the first healthy probe, so a loss in the one probe before that reads as a first grant.

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

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")
+	}
+}

scripts/retention-policy.json

@@ -25,9 +25,9 @@
     "scripts/check-published-versions.py — asserts the newest N versions plus every pinned version"
   ],
   "recorded": "2026-10-29",
-  "recorded_by": "CC 2026-10-29: day0_agent 0.170.0 (operator vouch 2026-10-29 18:57:48 CET, read from the hub log: agent=0.170.0, bundle 03f2ff64… = the release; the save took 38.3 s, R-1346); earlier 0.169.0 (operator vouch 2026-10-29 14:06:09 CET, read from the hub log: agent=0.169.0, bundle 3ca33f9c… = the release; his browser got a 504 but the save went through); earlier 0.168.0 (vouch 10:21:56 CET); 0.167.0 (vouch 2026-10-27); 0.166.0 (vouch 2026-10-26 10:04:55 CET); D50 = A (operator 2026-10-25); earlier history: R-287 (2026-08-09), R-291 (2026-10-05)",
+  "recorded_by": "CC 2026-10-30: day0_agent 0.171.0 (operator vouch 2026-10-30 10:47:36 CET, read from the hub log: agent=0.171.0, bundle 95f977f6… = the release; the save took 132 ms with hub 0.178.0, R-1346); earlier 0.170.0 (operator vouch 2026-10-29 18:57:48 CET, read from the hub log: agent=0.170.0, bundle 03f2ff64… = the release; the save took 38.3 s, R-1346); earlier 0.169.0 (operator vouch 2026-10-29 14:06:09 CET, read from the hub log: agent=0.169.0, bundle 3ca33f9c… = the release; his browser got a 504 but the save went through); earlier 0.168.0 (vouch 10:21:56 CET); 0.167.0 (vouch 2026-10-27); 0.166.0 (vouch 2026-10-26 10:04:55 CET); D50 = A (operator 2026-10-25); earlier history: R-287 (2026-08-09), R-291 (2026-10-05)",
   "pinned": {
     "hub_min_agent": "0.158.1",
-    "day0_agent": "0.170.0"
+    "day0_agent": "0.171.0"
   }
 }