From ec7e699fd77ed675f00c042fe3a1e0cabca4af9c Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Sat, 14 Nov 2026 19:09:21 +0100 Subject: [PATCH] =?UTF-8?q?agent=20(unreleased):=20fixes=20after=20an=20in?= =?UTF-8?q?dependent=20review=20=E2=80=94=20one=20lock=20for=20the=20write?= =?UTF-8?q?rs=20of=20agent.json,=20the=20trust=20run=20serialised=20and=20?= =?UTF-8?q?bounded,=20the=20CA=20copy=20keeps=20its=20previous=20root,=20t?= =?UTF-8?q?he=20profile=20stanza=20from=20the=20wrapper's=20answer,=20a=20?= =?UTF-8?q?stale=20give-up=20ends,=20both=20boot=20tokens=20from=20one=20r?= =?UTF-8?q?ead?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS --- CHANGELOG.md | 17 ++++ cmd/felhom-agent/config_writers_lock_test.go | 62 +++++++++++++ configs/felhom-os-apply | 20 +++- configs/test_felhom_os_apply.py | 23 ++++- internal/config/filelock.go | 12 +++ internal/localapi/backup_target.go | 3 + internal/localapi/disks.go | 5 +- internal/localapi/disks_test.go | 3 + internal/localapi/guest_boot_key_test.go | 7 ++ internal/localapi/guestpower.go | 15 +++ internal/localapi/guestpower_test.go | 35 +++++++ internal/localapi/intermediary.go | 15 +++ internal/osupdate/leg.go | 1 + internal/osupdate/profilerefresh.go | 97 ++++++++++++++------ internal/osupdate/profilerefresh_test.go | 53 +++++++---- internal/osupdate/pvecacopy.go | 2 +- internal/pbsdr/manager.go | 3 + internal/pvetrust/pvetrust.go | 19 +++- 18 files changed, 333 insertions(+), 59 deletions(-) create mode 100644 cmd/felhom-agent/config_writers_lock_test.go create mode 100644 internal/config/filelock.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 8055d68..81484ac 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,23 @@ Commit only. Each part can be released alone; none needs release 2b. No `configs/` change in this section. +- **Fixes after an independent review of the night's code (2026-11-14; felhom.eu + `documentation/audits/night-build-2026-11-14/review/`).** (1) `config.FileMu`: the three functions that read + `agent.json` whole and write it whole (the trust move, the PBS seed, the backup-target move) take one lock — two of + them could interleave and the second put back the document it read before the first one's change; pinned from the + source by `TestAgentJSONWritersTakeTheSharedLock`. (2) `pvetrust.Manager.Ensure` runs one at a time (start, timer, + a failed collect and a bundle install could overlap, and the second parked the already-moved file as the „before” + copy), and its root step has a 90-second deadline (it runs on the start path and inside the report loop). (3) **The + CA copy keeps its previous certificate behind the new one** (`configs/felhom-os-apply`, mode `pve-ca-copy`): the + copy was replaced before anything could be proven with the new root, and Proxmox serves its old certificate until + pveproxy is reloaded — an agent that restarted in that window had no root that verified it. At most two + certificates; the same source is still „same”. `configs/` changes again, so the release needs both signed jobs. + (4) The profile-refresh stanza is built from the wrapper's ANSWER (its record of the last refresh comes back at + every ask); the record file is a bonus — its folder is root-only on a box where a signed job made it first (read in + source, not on a box). `rewritten` is absent when not known. (5) A watchdog give-up is forgotten when the guest is + no longer the watchdog's (onboot off, locked, destroyed) — it was reported for ever. (6) `/disks` sends both boot + tokens from ONE read of the guest's init (`GuestBootTokens`). 13 mutations seen red, two after a mutant that did + not compile was done again. - **The hub is told what the kernel clean-up did and what the profile refresh did (R-1383; felhom.eu `11` §5.11.1, §5.12).** (1) The clean-up's report carries `kernel_cleanup` (`osupdate.CleanupDetail`: removed, kept, bytes_gained, leftovers). It still has no `kernel` view and `release_id` stays `kernel-cleanup` — the hub reads only those two as diff --git a/cmd/felhom-agent/config_writers_lock_test.go b/cmd/felhom-agent/config_writers_lock_test.go new file mode 100644 index 0000000..415a42c --- /dev/null +++ b/cmd/felhom-agent/config_writers_lock_test.go @@ -0,0 +1,62 @@ +package main + +import ( + "go/ast" + "go/parser" + "go/token" + "testing" +) + +// Three functions in this process read agent.json whole, change one section and write it whole: the trust move, the +// PBS seed and the backup-target move. Without one shared lock two of them interleave and the second puts back the +// document it read before the first one's change (found by review, 2026-11-14). Each must take config.FileMu as its +// FIRST statement and release it by defer — asserted from the source, because the race itself is not a thing a unit +// test can stage reliably. +func TestAgentJSONWritersTakeTheSharedLock(t *testing.T) { + for _, w := range []struct{ file, fn string }{ + {"../../internal/pvetrust/pvetrust.go", "writeConfig"}, + {"../../internal/pbsdr/manager.go", "seedEscrowStorageID"}, + {"../../internal/localapi/backup_target.go", "setConfiguredBackupTarget"}, + } { + f, err := parser.ParseFile(token.NewFileSet(), w.file, nil, 0) + if err != nil { + t.Fatalf("%s: %v", w.file, err) + } + found := false + for _, d := range f.Decls { + fn, ok := d.(*ast.FuncDecl) + if !ok || fn.Name.Name != w.fn || fn.Body == nil { + continue + } + found = true + isLockCall := func(e ast.Expr, name string) bool { + c, ok := e.(*ast.CallExpr) + if !ok { + return false + } + sel, ok := c.Fun.(*ast.SelectorExpr) + if !ok || sel.Sel.Name != name { + return false + } + inner, ok := sel.X.(*ast.SelectorExpr) + if !ok || inner.Sel.Name != "FileMu" { + return false + } + pkg, ok := inner.X.(*ast.Ident) + return ok && pkg.Name == "config" + } + if len(fn.Body.List) < 2 { + t.Errorf("%s %s: too short to hold the lock", w.file, w.fn) + continue + } + first, ok1 := fn.Body.List[0].(*ast.ExprStmt) + second, ok2 := fn.Body.List[1].(*ast.DeferStmt) + if !ok1 || !isLockCall(first.X, "Lock") || !ok2 || !isLockCall(second.Call, "Unlock") { + t.Errorf("%s %s: must start with config.FileMu.Lock() and defer config.FileMu.Unlock()", w.file, w.fn) + } + } + if !found { + t.Errorf("%s: function %s not found — a writer of agent.json was renamed; keep it under the shared lock and update this test", w.file, w.fn) + } + } +} diff --git a/configs/felhom-os-apply b/configs/felhom-os-apply index 049a68b..ea00a43 100755 --- a/configs/felhom-os-apply +++ b/configs/felhom-os-apply @@ -1216,7 +1216,8 @@ class Apply: def pve_ca_copy(self): """Copy exactly PVE_CA_SOURCE to exactly PVE_CA_COPY — only if the source is ONE CA certificate that has not ended — written whole or not at all (a root-owned temp file beside the target, fsync, rename). "same" when the - copy already holds the source's bytes. The bytes that are checked are the bytes that are written.""" + copy already starts with the source's bytes. The bytes that are checked are the bytes that are written first; + behind them the copy keeps its own previous certificate (see below), so the copy holds one or two.""" r = self.r res = {"outcome": None, "path": PVE_CA_COPY} self.report["pve_ca_copy"] = res @@ -1253,11 +1254,20 @@ class Apply: have = r.read_bytes(PVE_CA_COPY) except OSError: have = None - if have == data: - res["outcome"] = "same" + if have is not None and have.startswith(data): + res["outcome"] = "same" # the source's certificate is already first in the copy return 0 - r.put_file(PVE_CA_COPY, data, 0o644) - res["outcome"], res["replaced"] = "written", have is not None + # The copy the agent trusts by is replaced BEFORE anything can be proven with the new one (Proxmox serves its + # old certificate until pveproxy is reloaded). So the copy's previous FIRST certificate — written by this same + # step, so already checked as a CA — is kept behind the new one: the agent then trusts both roots across the + # change, also after a restart. At most two certificates; an ended one verifies nothing. (Review, 2026-11-14.) + want, kept = data, False + if have: + prev = PEM_CERT_RE.findall(have) + if prev and b"PRIVATE KEY" not in have and prev[0].strip() != certs[0].strip(): + want, kept = data + prev[0] + b"\n", True + r.put_file(PVE_CA_COPY, want, 0o644) + res["outcome"], res["replaced"], res["kept_previous"] = "written", have is not None, kept r.log(f"os-apply: PVE CA COPY written {PVE_CA_COPY} sha256={res['sha256'][:16]} ends={res['not_after']} " f"({'replaced an older copy' if have is not None else 'first copy'})") return 0 diff --git a/configs/test_felhom_os_apply.py b/configs/test_felhom_os_apply.py index 80dd1f7..46138a7 100644 --- a/configs/test_felhom_os_apply.py +++ b/configs/test_felhom_os_apply.py @@ -2702,7 +2702,28 @@ class PVECACopy(unittest.TestCase): f = TFake(source=CA_PEM_2, copy=CA_PEM) rc, rep = run(f) self.assertEqual((rc, rep["pve_ca_copy"]["outcome"], rep["pve_ca_copy"]["replaced"]), (0, "written", True), rep) - self.assertEqual(f.tree[osapply.PVE_CA_COPY], CA_PEM_2) + # the new certificate FIRST, and the copy's previous one kept behind it: Proxmox serves its old certificate until + # pveproxy is reloaded, and an agent that restarts in that window must still have a root that verifies it + self.assertTrue(f.tree[osapply.PVE_CA_COPY].startswith(CA_PEM_2)) + self.assertEqual(osapply.PEM_CERT_RE.findall(f.tree[osapply.PVE_CA_COPY]), + osapply.PEM_CERT_RE.findall(CA_PEM_2) + osapply.PEM_CERT_RE.findall(CA_PEM)) + self.assertTrue(rep["pve_ca_copy"]["kept_previous"]) + self.assertEqual(f.openssl_stdin, [CA_PEM_2.decode()], "only the SOURCE is checked by openssl") + # the same source again: nothing is written (the copy already starts with it) + f2 = TFake(source=CA_PEM_2, copy=f.tree[osapply.PVE_CA_COPY]) + rc, rep = run(f2) + self.assertEqual((rc, rep["pve_ca_copy"]["outcome"], f2.puts), (0, "same", []), rep) + # a third change: never more than two certificates — the new one and the one that was first + f3 = TFake(source=CA_PEM, copy=f.tree[osapply.PVE_CA_COPY]) + rc, rep = run(f3) + self.assertEqual(rc, 0, rep) + self.assertEqual(osapply.PEM_CERT_RE.findall(f3.tree[osapply.PVE_CA_COPY]), + osapply.PEM_CERT_RE.findall(CA_PEM) + osapply.PEM_CERT_RE.findall(CA_PEM_2)) + # a first copy keeps nothing behind it + f4 = TFake() + rc, rep = run(f4) + self.assertFalse(rep["pve_ca_copy"]["kept_previous"]) + self.assertEqual(f4.tree[osapply.PVE_CA_COPY], CA_PEM) def test_a_source_that_is_not_a_ca_certificate_is_refused(self): self.refused(TFake(ca=False), "T3") # a leaf certificate diff --git a/internal/config/filelock.go b/internal/config/filelock.go new file mode 100644 index 0000000..a9b02cb --- /dev/null +++ b/internal/config/filelock.go @@ -0,0 +1,12 @@ +package config + +import "sync" + +// FileMu is held by EVERY read-modify-write of agent.json inside this process: the trust move (pvetrust), the PBS +// seed (pbsdr) and the backup-target move (localapi). Each of them reads the whole file, changes one section and +// writes the whole file back in place — without one lock two of them could interleave, and the second writer would +// put back the document it read BEFORE the first one's change (a silently reverted `escrow.pbs_storage_id`, +// `backup.local_backup_target` or trust section). Found by review on 2026-11-14, the night the third writer was +// added. Hold it for the whole read … write, never across a call to Proxmox or the root wrapper. +// Pinned by TestAgentJSONWritersTakeTheSharedLock (cmd/felhom-agent). +var FileMu sync.Mutex diff --git a/internal/localapi/backup_target.go b/internal/localapi/backup_target.go index 1812a3f..edc4d48 100644 --- a/internal/localapi/backup_target.go +++ b/internal/localapi/backup_target.go @@ -4,6 +4,7 @@ import ( "context" "encoding/json" "fmt" + "gitea.dooplex.hu/admin/felhom-agent/internal/config" "net/http" "os" "path/filepath" @@ -148,6 +149,8 @@ func (s *Server) validateBackupTargetMount(ctx context.Context, where string) er // agent-owned 0600, so the non-root agent cannot rename into that directory. A recovery copy is // parked first, so a torn write is recoverable. func (s *Server) setConfiguredBackupTarget(id string) error { + config.FileMu.Lock() // one writer of agent.json at a time in this process (config.FileMu) + defer config.FileMu.Unlock() path := s.configPath if path == "" { return fmt.Errorf("no config path known to this agent (env-only config)") diff --git a/internal/localapi/disks.go b/internal/localapi/disks.go index 9d15cf6..507823e 100644 --- a/internal/localapi/disks.go +++ b/internal/localapi/disks.go @@ -90,6 +90,8 @@ type GuestAttacher interface { // GuestBootKey is the same signal built from the kernel's boot_id, which a step of the host's clock cannot // move (R-1395). "" = not readable; the controller then reads GuestBootID. GuestBootKey(ctx context.Context, vmid int) string + // GuestBootTokens returns (GuestBootID, GuestBootKey) from one read — what /disks sends. + GuestBootTokens(ctx context.Context, vmid int) (id, key string) // AttachBind is the LEGACY per-drive `pct set -mpN` bind (pre-intermediary). Retained for the // transition; new attaches use AttachDrive. AttachBind(ctx context.Context, vmid int, mountKey, where string) error @@ -437,8 +439,7 @@ func (s *Server) handleDisks(w http.ResponseWriter, r *http.Request, vmid int) { // R-1395: guest_boot_key is the clock-proof form (kernel boot_id); guest_boot_id stays for older controllers. bootID, bootKey := "", "" if s.guestAttach != nil { - bootID = s.guestAttach.GuestBootID(r.Context(), vmid) - bootKey = s.guestAttach.GuestBootKey(r.Context(), vmid) + bootID, bootKey = s.guestAttach.GuestBootTokens(r.Context(), vmid) } writeOK(w, map[string]any{"vmid": vmid, "disks": out, "guest_boot_id": bootID, "guest_boot_key": bootKey}) } diff --git a/internal/localapi/disks_test.go b/internal/localapi/disks_test.go index 7140ef1..bbf750a 100644 --- a/internal/localapi/disks_test.go +++ b/internal/localapi/disks_test.go @@ -467,6 +467,9 @@ func (f *fakeGuestAttacher) AttachDrive(_ context.Context, _ int, where string) func (f *fakeGuestAttacher) GuestSeesMount(_ context.Context, _ int, _ string) bool { return true } func (f *fakeGuestAttacher) GuestBootID(_ context.Context, _ int) string { return "boot-1" } func (f *fakeGuestAttacher) GuestBootKey(_ context.Context, _ int) string { return "key-1" } +func (f *fakeGuestAttacher) GuestBootTokens(_ context.Context, _ int) (string, string) { + return "boot-1", "key-1" +} func (f *fakeGuestAttacher) attachDriveCount() int { f.mu.Lock() defer f.mu.Unlock() diff --git a/internal/localapi/guest_boot_key_test.go b/internal/localapi/guest_boot_key_test.go index d7127ec..8e82ed8 100644 --- a/internal/localapi/guest_boot_key_test.go +++ b/internal/localapi/guest_boot_key_test.go @@ -76,6 +76,13 @@ func TestGuestBootKey_AClockStepDoesNotMoveIt(t *testing.T) { t.Errorf("the old token must still be sent when the boot_id is unreadable") } } + // what /disks sends: both tokens from ONE read of the guest's init — the init is asked for once, not twice + bootID, start = "5b1f6c1e-8f0a-4c56-9d1c-0a8c3b7d2e11", "4242" + reads := 0 + procStarttimeFn = func(string) string { reads++; return start } + if id, key := b.GuestBootTokens(ctx, 9201); id != "1794112550-4242" || key != "5b1f6c1e-8f0a-4c56-9d1c-0a8c3b7d2e11-4242" || reads != 1 { + t.Errorf("GuestBootTokens = %q, %q after %d read(s) of the init — want both tokens from ONE read", id, key, reads) + } bootID, start = "5b1f6c1e-8f0a-4c56-9d1c-0a8c3b7d2e11", "" // the guest does not run if k := b.GuestBootKey(ctx, 9201); k != "" { t.Errorf("a guest that does not run gave the key %q", k) diff --git a/internal/localapi/guestpower.go b/internal/localapi/guestpower.go index 78c3063..9c06a5d 100644 --- a/internal/localapi/guestpower.go +++ b/internal/localapi/guestpower.go @@ -152,6 +152,19 @@ func (s *Server) GuestPowerTick(ctx context.Context) { s.logger.Warn("guest-power: guest list unavailable — skipping sweep (ownership unproven)", "err", err) return } + // A guest that left the list (destroyed, or re-made under another number) takes its attempt record with it — a + // give-up for a guest that no longer exists would ride every host report until the agent restarts. + present := make(map[int]bool, len(guests)) + for _, g := range guests { + present[g.VMID] = true + } + guestPowerMu.Lock() + for vmid := range s.guestPower { + if !present[vmid] { + delete(s.guestPower, vmid) + } + } + guestPowerMu.Unlock() var stopped int for _, g := range guests { if ctx.Err() != nil { @@ -202,6 +215,7 @@ func (s *Server) recoverOneStoppedGuest(ctx context.Context, g proxmox.Guest) { // SCENARIO B — a deliberately stopped guest is left alone, forever. onboot:0 means the operator // (or the golden-image provisioning) does not want this guest running. if !onboot { + s.forgetGuestPower(g.VMID) // not ours to start any more: a give-up for it must not be reported for ever return } @@ -211,6 +225,7 @@ func (s *Server) recoverOneStoppedGuest(ctx context.Context, g proxmox.Guest) { if lock != "" { s.logger.Info("guest-power: guest is stopped but LOCKED — leaving it to the stale-lock path", "vmid", g.VMID, "lock", lock) + s.forgetGuestPower(g.VMID) // another operation owns it now; if it ends stopped, the three tries start again return } diff --git a/internal/localapi/guestpower_test.go b/internal/localapi/guestpower_test.go index 6dd9de2..13eab53 100644 --- a/internal/localapi/guestpower_test.go +++ b/internal/localapi/guestpower_test.go @@ -281,3 +281,38 @@ func TestGuestPower_GiveUpIsReportedUntilTheGuestRuns(t *testing.T) { t.Fatalf("the guest runs again and the stanza is still %#v", st) } } + +// Found by review, 2026-11-14: the give-up was forgotten only when the guest was seen RUNNING. A guest the operator +// then switches to onboot:0, a guest another operation locks, and a guest that is destroyed would be reported as +// „given up” for ever (the hub's alarm could never clear). Each of the three ends the report. +func TestGuestPower_GiveUpEndsWhenTheGuestIsNoLongerOurs(t *testing.T) { + for _, c := range []struct { + name string + change func(ctl *fakeGuestPowerCtl) + }{ + {"onboot switched off", func(ctl *fakeGuestPowerCtl) { ctl.onboot = map[int]bool{9201: false} }}, + {"locked by another operation", func(ctl *fakeGuestPowerCtl) { ctl.locks = map[int]string{9201: "backup"} }}, + {"destroyed", func(ctl *fakeGuestPowerCtl) { ctl.guests = nil }}, + } { + ctl := &fakeGuestPowerCtl{ + guests: []proxmox.Guest{{VMID: 9201, Status: "stopped"}}, + locks: map[int]string{9201: ""}, + onboot: map[int]bool{9201: true}, + startErr: errors.New("cannot start"), + } + now := time.Date(2026, 11, 14, 2, 0, 0, 0, time.UTC) + s := gpServer(t, ctl, func() time.Time { return now }) + for i := 0; i < guestPowerMaxAttempts+1; i++ { + s.GuestPowerTick(context.Background()) + now = now.Add(10 * time.Minute) + } + if len(s.GuestPowerGaveUp()) != 1 { + t.Fatalf("%s: setup — no give-up recorded", c.name) + } + c.change(ctl) + s.GuestPowerTick(context.Background()) + if g := s.GuestPowerGaveUp(); len(g) != 0 { + t.Errorf("%s: the give-up is still reported: %+v", c.name, g) + } + } +} diff --git a/internal/localapi/intermediary.go b/internal/localapi/intermediary.go index 5e4d6a2..5d4f4c8 100644 --- a/internal/localapi/intermediary.go +++ b/internal/localapi/intermediary.go @@ -324,6 +324,21 @@ func (b *GuestBinder) GuestBootKey(ctx context.Context, vmid int) string { return guestBootKey(hostBootIDFn(), start) } +// GuestBootTokens returns both tokens from ONE read of the guest's init: the old token and the key always describe +// the same moment. Read separately, one could succeed and the other fail (the guest stops between the two) — the +// controller would then get an old token with no key, read „an older agent”, and recreate every drive-backed app. +func (b *GuestBinder) GuestBootTokens(ctx context.Context, vmid int) (id, key string) { + start := b.guestInitStart(ctx, vmid) + if start == "" { + return "", "" + } + bt := hostBtimeFn() + if bt == "" { + bt = "0" + } + return bt + "-" + start, guestBootKey(hostBootIDFn(), start) +} + // guestBootKey joins the two halves; "" when either is missing or the boot_id is not the kernel's shape. func guestBootKey(bootID, start string) string { if start == "" || !kernelBootIDRe.MatchString(bootID) { diff --git a/internal/osupdate/leg.go b/internal/osupdate/leg.go index 483a9da..ef731c0 100644 --- a/internal/osupdate/leg.go +++ b/internal/osupdate/leg.go @@ -232,6 +232,7 @@ type Leg struct { block *hub.WireOSUpdate profileAsk string // how the last ask of the profile refresh ended in THIS process ("" = never asked) profileAskAt time.Time + profileLast ProfileRefreshStatus // the last refresh as the wrapper answered it to this process } // planFile / reportFile: the plan the agent writes and the copy of the report the wrapper keeps beside it (R-868). diff --git a/internal/osupdate/profilerefresh.go b/internal/osupdate/profilerefresh.go index 9ed4822..b0bc613 100644 --- a/internal/osupdate/profilerefresh.go +++ b/internal/osupdate/profilerefresh.go @@ -30,6 +30,9 @@ type ProfileRefreshResult struct { Active bool `json:"active"` } `json:"restarted"` Seconds float64 `json:"seconds"` + // The wrapper's own record of the refresh BEFORE this ask (it answers them at every ask, also "not needed"). + LastRefreshKernel string `json:"last_refresh_kernel"` + LastRefreshAt string `json:"last_refresh_at"` } // DefaultProfileRecordPath is where the root wrapper keeps the record of its last refresh (PROFILE_STATE, 0644). @@ -42,7 +45,7 @@ const DefaultProfileRecordPath = "/var/lib/felhom-os-apply/profile-refresh.json" type ProfileRefreshStatus struct { Kernel string `json:"kernel,omitempty"` // the kernel the last refresh ran on At string `json:"at,omitempty"` // RFC3339, when - Rewritten int `json:"rewritten"` // how many compiled profiles changed + Rewritten *int `json:"rewritten,omitempty"` // how many compiled profiles changed; nil = not known to this process Restarted []string `json:"restarted,omitempty"` // units it restarted (failed, with a stale profile) LastAsk string `json:"last_ask,omitempty"` // refreshed | not_needed | failed | refused | no_answer LastAskAt string `json:"last_ask_at,omitempty"` @@ -50,16 +53,27 @@ type ProfileRefreshStatus struct { var profileNameRe = regexp.MustCompile(`^[A-Za-z0-9@._:+-]{1,120}$`) -// ProfileRefreshStanza builds the stanza, or an UNTYPED nil when there is nothing to say (no record and never asked: -// a BYO host, or an agent that did not ask yet) — the report then omits the field. It reads one small root-written -// file and never calls the wrapper. Names that are not plain unit / kernel names are dropped, the list is capped. +// ProfileRefreshStanza builds the stanza, or an UNTYPED nil when there is nothing to say (never asked and no record: a +// BYO host, or an agent that did not ask yet) — the report then omits the field. +// +// Two sources, the first that knows wins per field. (1) What the wrapper ANSWERED to this process's last ask: a +// refresh gives everything; "not needed" gives the kernel and time of the earlier refresh (the wrapper answers its own +// record at every ask) — so the last refresh is still told after an agent restart, without the detail. (2) The +// wrapper's record file, when this process may read it: on boxes where its folder was first made by a signed job it +// is root-only (0700), so the file is a bonus, never the only source (found by review, 2026-11-14; not read on a box). +// It never calls the wrapper. Names that are not plain unit / kernel names are dropped, the list is capped. func (l *Leg) ProfileRefreshStanza() any { + l.mu.Lock() + st, ask, at := l.profileLast, l.profileAsk, l.profileAskAt + l.mu.Unlock() + have := ask != "" + if have { + st.LastAsk, st.LastAskAt = ask, at.UTC().Format(time.RFC3339) + } path := l.ProfileRecordPath if path == "" { path = DefaultProfileRecordPath } - var st ProfileRefreshStatus - have := false if raw, err := os.ReadFile(path); err == nil && len(raw) < 64<<10 { var rec struct { Kernel string `json:"kernel"` @@ -69,37 +83,60 @@ func (l *Leg) ProfileRefreshStanza() any { } if json.Unmarshal(raw, &rec) == nil && (rec.Kernel != "" || rec.At != "") { have = true - if profileNameRe.MatchString(rec.Kernel) { - st.Kernel = rec.Kernel - } - if _, err := time.Parse(time.RFC3339, rec.At); err == nil { - st.At = rec.At - } - st.Rewritten = len(rec.Rewritten) - for _, u := range rec.Restarted { - if len(st.Restarted) < 16 && profileNameRe.MatchString(u) { - st.Restarted = append(st.Restarted, u) - } + fromRec := profileStatusFrom(rec.Kernel, rec.At, rec.Rewritten, rec.Restarted, true) + if st.At == "" || fromRec.At == st.At || st.Rewritten == nil { + fromRec.LastAsk, fromRec.LastAskAt = st.LastAsk, st.LastAskAt + st = fromRec } } } - l.mu.Lock() - ask, at := l.profileAsk, l.profileAskAt - l.mu.Unlock() - if ask != "" { - have = true - st.LastAsk, st.LastAskAt = ask, at.UTC().Format(time.RFC3339) - } if !have { return nil } return st } -func (l *Leg) noteProfileAsk(outcome string) { +// profileStatusFrom checks and bounds what goes to the hub. detail=false: the count and the units are not known. +func profileStatusFrom(kernel, at string, rewritten, restarted []string, detail bool) ProfileRefreshStatus { + var st ProfileRefreshStatus + if profileNameRe.MatchString(kernel) { + st.Kernel = kernel + } + if _, err := time.Parse(time.RFC3339, at); err == nil { + st.At = at + } + if detail { + n := len(rewritten) + st.Rewritten = &n + for _, u := range restarted { + if len(st.Restarted) < 16 && profileNameRe.MatchString(u) { + st.Restarted = append(st.Restarted, u) + } + } + } + return st +} + +// noteProfileAsk remembers how an ask ended and, when the wrapper answered, what it said about the last refresh. +func (l *Leg) noteProfileAsk(outcome string, res *ProfileRefreshResult) { l.mu.Lock() + defer l.mu.Unlock() l.profileAsk, l.profileAskAt = outcome, l.now() - l.mu.Unlock() + if res == nil { + return + } + switch outcome { + case "refreshed": + units := make([]string, 0, len(res.Restarted)) + for _, u := range res.Restarted { + units = append(units, u.Unit) + } + l.profileLast = profileStatusFrom(res.Kernel, l.now().UTC().Format(time.RFC3339), res.Rewritten, units, true) + case "not_needed": + if res.LastRefreshAt != "" || res.LastRefreshKernel != "" { + l.profileLast = profileStatusFrom(res.LastRefreshKernel, res.LastRefreshAt, nil, nil, false) + } + } } // ProfileGate takes the heavy-op gate (a backup, a restore-test or an OS step must not run beside the refresh). @@ -142,15 +179,15 @@ func (l *Leg) ProfileRefresh(ctx context.Context, why string, gate ProfileGate, switch { case err != nil: lg.Warn("osupdate: profile refresh — the wrapper gave no answer; the next agent start asks again", "err", err, "took", took) - l.noteProfileAsk("no_answer") + l.noteProfileAsk("no_answer", nil) return "" case wr.refused(): lg.Info("osupdate: profile refresh refused (an older wrapper that does not know the mode, or a BYO host)", "refused", string(wr.Refused)) - l.noteProfileAsk("refused") + l.noteProfileAsk("refused", nil) return "" case wr.failed(): lg.Error("osupdate: profile refresh FAILED — the profiles are as before; the next agent start asks again", "failed", string(wr.Failed), "took", took) - l.noteProfileAsk("failed") + l.noteProfileAsk("failed", nil) return "failed" } var res ProfileRefreshResult @@ -174,7 +211,7 @@ func (l *Leg) ProfileRefresh(ctx context.Context, why string, gate ProfileGate, lg.Warn("osupdate: profile refresh — the wrapper answered with no outcome this agent knows", "outcome", res.Outcome) } if res.Outcome == "refreshed" || res.Outcome == "not_needed" { - l.noteProfileAsk(res.Outcome) + l.noteProfileAsk(res.Outcome, &res) } return res.Outcome } diff --git a/internal/osupdate/profilerefresh_test.go b/internal/osupdate/profilerefresh_test.go index 10c53c3..71cf12e 100644 --- a/internal/osupdate/profilerefresh_test.go +++ b/internal/osupdate/profilerefresh_test.go @@ -100,49 +100,66 @@ func TestProfileRefresh_RefusedAndFailed(t *testing.T) { } // R-1383 (release 3): the refresh restarted a failed service on the N100 and only the box's journal knew. The stanza -// that rides the host report: nothing before any refresh (an UNTYPED nil — the report omits the field); after a -// refresh, the root wrapper's own record (so it outlives an agent restart) and how this process's last ask ended. +// that rides the host report: nothing before any ask (an UNTYPED nil — the report omits the field); after a refresh, +// everything; after an agent RESTART, the kernel and time of that refresh again — from the wrapper's answer to the new +// process's ask, because the wrapper's record FILE may be root-only on a box (its folder is 0700 where a signed job +// made it first). Where the file can be read, it adds the detail back. // COMPANION RED-PROOFS (observed, felhom.eu audits/night-build-2026-11-14/B/redproof-agent-b3.txt). func TestProfileRefreshStanza_RecordAndLastAsk(t *testing.T) { w := &fakeWrapper{t: t, profileRep: refreshed()} l, _ := newLeg(t, w, &hub.WireOSUpdate{Ring: 1, Enabled: true}) - rec := filepath.Join(t.TempDir(), "profile-refresh.json") - l.ProfileRecordPath = rec + unreadable := filepath.Join(t.TempDir(), "root-only", "profile-refresh.json") // does not exist: as a 0700 folder reads + l.ProfileRecordPath = unreadable now := time.Date(2026, 11, 14, 11, 30, 11, 0, time.UTC) l.Now = func() time.Time { return now } if st := l.ProfileRefreshStanza(); st != nil { - t.Fatalf("before any refresh the stanza is %#v, want an untyped nil", st) + t.Fatalf("before any ask the stanza is %#v, want an untyped nil", st) } - // the wrapper refreshes and writes ITS record (the fake wrapper does not, so the test writes what the real one does) if got := l.ProfileRefresh(context.Background(), "agent start", nil, 1, time.Second); got != "refreshed" { t.Fatalf("outcome = %q", got) } + b, _ := json.Marshal(l.ProfileRefreshStanza()) + if string(b) != `{"kernel":"7.0.14-28-pve","at":"2026-11-14T11:30:11Z","rewritten":1,"restarted":["chrony.service"],"last_ask":"refreshed","last_ask_at":"2026-11-14T11:30:11Z"}` { + t.Fatalf("stanza after a refresh, record file unreadable = %s", b) + } + // an agent restart: a new process asks, the wrapper answers "not needed" with ITS record of the last refresh + l2, _ := newLeg(t, &fakeWrapper{t: t, profileRep: &WrapperReport{ProfileRefresh: json.RawMessage( + `{"outcome":"not_needed","reason":"this kernel was done","kernel":"7.0.14-28-pve","last_refresh_kernel":"7.0.14-28-pve","last_refresh_at":"2026-11-14T11:30:11Z"}`)}}, + &hub.WireOSUpdate{Ring: 1, Enabled: true}) + l2.ProfileRecordPath = unreadable + l2.Now = func() time.Time { return now.Add(3 * time.Hour) } + if st := l2.ProfileRefreshStanza(); st != nil { + t.Fatalf("a new process that has not asked and cannot read the record: %#v, want nil", st) + } + if got := l2.ProfileRefresh(context.Background(), "agent start", nil, 1, time.Second); got != "not_needed" { + t.Fatalf("outcome = %q", got) + } + b, _ = json.Marshal(l2.ProfileRefreshStanza()) + if string(b) != `{"kernel":"7.0.14-28-pve","at":"2026-11-14T11:30:11Z","last_ask":"not_needed","last_ask_at":"2026-11-14T14:30:11Z"}` { + t.Fatalf("stanza after an agent restart (the wrapper's answer, no detail) = %s", b) + } + // where the record file CAN be read, the detail is back — and a name that is not a unit name is dropped + rec := filepath.Join(t.TempDir(), "profile-refresh.json") if err := os.WriteFile(rec, []byte(`{"at":"2026-11-14T11:30:11Z","kernel":"7.0.14-28-pve","restarted":["chrony.service","bad name; rm -rf"],`+ - `"rewritten":["f6da0254.0/usr.sbin.chronyd","f6da0254.0/lxc-containers"]}`), 0o644); err != nil { + `"rewritten":["a","b"]}`), 0o644); err != nil { t.Fatal(err) } - b, _ := json.Marshal(l.ProfileRefreshStanza()) - if string(b) != `{"kernel":"7.0.14-28-pve","at":"2026-11-14T11:30:11Z","rewritten":2,"restarted":["chrony.service"],"last_ask":"refreshed","last_ask_at":"2026-11-14T11:30:11Z"}` { - t.Fatalf("stanza after a refresh = %s", b) - } - // an agent restart: a new process, the same record — the box's last refresh is still told - l2, _ := newLeg(t, &fakeWrapper{t: t}, &hub.WireOSUpdate{Ring: 1, Enabled: true}) l2.ProfileRecordPath = rec b, _ = json.Marshal(l2.ProfileRefreshStanza()) - if string(b) != `{"kernel":"7.0.14-28-pve","at":"2026-11-14T11:30:11Z","rewritten":2,"restarted":["chrony.service"]}` { - t.Fatalf("stanza after an agent restart = %s", b) + if string(b) != `{"kernel":"7.0.14-28-pve","at":"2026-11-14T11:30:11Z","rewritten":2,"restarted":["chrony.service"],"last_ask":"not_needed","last_ask_at":"2026-11-14T14:30:11Z"}` { + t.Fatalf("stanza with a readable record = %s", b) } // a failed ask is told, beside the older record - l2.Now = func() time.Time { return now.Add(time.Hour) } l2.Runner = (&fakeWrapper{t: t, profileRep: &WrapperReport{Failed: json.RawMessage(`{"code":"F1","reason":"apparmor_parser failed"}`)}}) + l2.Now = func() time.Time { return now.Add(4 * time.Hour) } if got := l2.ProfileRefresh(context.Background(), "agent start", nil, 1, time.Second); got != "failed" { t.Fatalf("outcome = %q", got) } b, _ = json.Marshal(l2.ProfileRefreshStanza()) - if !strings.Contains(string(b), `"last_ask":"failed","last_ask_at":"2026-11-14T12:30:11Z"`) || !strings.Contains(string(b), `"kernel":"7.0.14-28-pve"`) { + if !strings.Contains(string(b), `"last_ask":"failed","last_ask_at":"2026-11-14T15:30:11Z"`) || !strings.Contains(string(b), `"kernel":"7.0.14-28-pve"`) { t.Fatalf("stanza after a failed ask = %s", b) } - // a record that is not JSON, or huge, says nothing and breaks nothing + // a record that is not JSON says nothing and breaks nothing _ = os.WriteFile(rec, []byte("not json"), 0o644) l3, _ := newLeg(t, &fakeWrapper{t: t}, &hub.WireOSUpdate{Ring: 1, Enabled: true}) l3.ProfileRecordPath = rec diff --git a/internal/osupdate/pvecacopy.go b/internal/osupdate/pvecacopy.go index 1a0f131..c732737 100644 --- a/internal/osupdate/pvecacopy.go +++ b/internal/osupdate/pvecacopy.go @@ -26,7 +26,7 @@ type PVECACopyResult struct { // PVECACopy asks the wrapper to make or refresh the copy. An error names a refusal (T1–T3, or R11 from a wrapper that // does not know the mode yet) or a wrapper that gave no answer. func (l *Leg) PVECACopy(ctx context.Context) (PVECACopyResult, error) { - wr, err := l.call(ctx, "pveca"+l.now().UTC().Format("150405"), map[string]any{"release_id": "pve-ca-copy", + wr, err := l.call(ctx, "pveca"+l.now().UTC().Format("150405.000"), map[string]any{"release_id": "pve-ca-copy", "layer": LayerHost, "mode": "pve-ca-copy"}) if err != nil { return PVECACopyResult{}, err diff --git a/internal/pbsdr/manager.go b/internal/pbsdr/manager.go index 657966a..8b91004 100644 --- a/internal/pbsdr/manager.go +++ b/internal/pbsdr/manager.go @@ -27,6 +27,7 @@ import ( "encoding/json" "errors" "fmt" + "gitea.dooplex.hu/admin/felhom-agent/internal/config" "log/slog" "net/netip" "os" @@ -485,6 +486,8 @@ func (m *Manager) consumedFail(h, msg string, block *hub.WirePBSDR) { // value is NEVER clobbered (warn-and-keep). Unknown config keys are preserved verbatim // (map[string]RawMessage read-modify-write, atomic rename). func (m *Manager) seedEscrowStorageID(storageID string) error { + config.FileMu.Lock() // one writer of agent.json at a time in this process (config.FileMu) + defer config.FileMu.Unlock() if m.configPath == "" { return nil } diff --git a/internal/pvetrust/pvetrust.go b/internal/pvetrust/pvetrust.go index 6b9ce0a..382628f 100644 --- a/internal/pvetrust/pvetrust.go +++ b/internal/pvetrust/pvetrust.go @@ -25,6 +25,7 @@ import ( "context" "encoding/json" "fmt" + "gitea.dooplex.hu/admin/felhom-agent/internal/config" "log/slog" "os" "path/filepath" @@ -81,12 +82,16 @@ type Manager struct { // MinGap between two runs that a failed call asked for (default 10 minutes). MinGap time.Duration + runMu sync.Mutex // serialises Ensure mu sync.Mutex cur proxmox.TLSConfig status Status lastRun time.Time } +// copyStepTimeout bounds the root step that makes the CA copy. +const copyStepTimeout = 90 * time.Second + func (m *Manager) now() time.Time { if m.Now != nil { return m.Now() @@ -207,6 +212,11 @@ func causeText(cause string) string { // Ensure runs the order of the package comment once. why is a log word ("start", "daily", a trust cause). It returns // true when the running trust changed. func (m *Manager) Ensure(ctx context.Context, why string) bool { + // One run at a time. Ensure is called from the start, the timer, a failed collect and after a bundle install; two + // overlapping runs would both read the config, and the second would park the ALREADY-MOVED file as the "before" + // copy (losing the fingerprint from the recovery copy). Found by review, 2026-11-14. + m.runMu.Lock() + defer m.runMu.Unlock() m.mu.Lock() cur := m.cur m.lastRun = m.now() @@ -230,8 +240,11 @@ func (m *Manager) Ensure(ctx context.Context, why string) bool { if m.EnsureCopy == nil || m.Probe == nil { return false } - // 1. the copy - c, err := m.EnsureCopy(ctx) + // 1. the copy. The root step gets a deadline of its own: Ensure runs on the daemon's start path and inside the + // report loop, and a wrapper that hangs (sudo, a stuck read of /etc/pve) must not stop either. + cctx, ccancel := context.WithTimeout(ctx, copyStepTimeout) + c, err := m.EnsureCopy(cctx) + ccancel() if err != nil { lg.Warn("pvetrust: the root step gave no CA copy — the trust stays as it is", "err", err) set(modeOf(cur), ProblemCopyUnavailable, truncate(err.Error(), 240), nil) @@ -341,6 +354,8 @@ func truncate(s string, n int) string { // writeConfig sets proxmox.tls.ca_file and clears proxmox.tls.fingerprint in ONE write of agent.json. Every other key is // kept byte for byte. A recovery copy is parked in the state folder first; the result is read back and checked. func (m *Manager) writeConfig(caPath string) error { + config.FileMu.Lock() // one writer of agent.json at a time in this process (config.FileMu) + defer config.FileMu.Unlock() raw, err := os.ReadFile(m.ConfigPath) if err != nil { return err