From 29bebbb93787884178b3b7c98045327ecdb44811 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Wed, 7 Oct 2026 18:45:01 +0200 Subject: [PATCH] v0.303.0 (code): after a restart, a backup capture waits for the drive's bind (R-897) Co-Authored-By: Claude Opus 5.5 (1M context) Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS --- CHANGELOG.md | 13 +++ controller/internal/backup/backup.go | 9 ++ controller/internal/backup/driveready.go | 103 ++++++++++++++++++ controller/internal/backup/driveready_test.go | 78 +++++++++++++ controller/internal/backup/recovery_unit.go | 5 + 5 files changed, 208 insertions(+) create mode 100644 controller/internal/backup/driveready.go create mode 100644 controller/internal/backup/driveready_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 67612f8..2cb126e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,16 @@ +## v0.303.0 — after a restart, a backup capture waits for the drive (R-897; `09` §3 decision 176) (2026-10-07) + +**MinAgent: 0.131.0** (unchanged — no agent route is read; the signal is the controller's own mount table). + +- **R-897:** after a host restart the agent binds each drive under `/mnt/felhom-drives` and may normalize it once more + (umount + mount) when the guest started after the first bind; a recovery-unit capture in that second failed + (`mkdir /mnt/felhom-drives/hdd_1/backups: permission denied`, demo-hp 2026-10-07) and the operator got a false backup + failure. Now, for 10 minutes after the controller starts (`backup.DriveWaitWindow`), a capture for an app on a drive + runs only once that drive is a LIVE mount in the controller's own namespace (`/proc/self/mountinfo`, the same signal + the startup app gate uses): the 5-minute refresh skips the app until then; a data run waits (polls every 5 s). After + the window it runs anyway and says so once at WARN. The agent's bind order is unchanged. `internal/backup/driveready.go`; + tests `TestDriveReady_*` (3; red-proved: without the call the capture ran while the drive was not bound). + ## Unreleased (2026-10-07) — the shared rule file; no code change - `.claude/rules/unprompted-work.md`: rule 11 (every helper prompt carries the brief's fences in full, `09` §3 decision 160) and the §1 line „no hub image build or hub deploy in a session the operator does not attend" (decision 162). Identical in all five copies. diff --git a/controller/internal/backup/backup.go b/controller/internal/backup/backup.go index 30d6f36..cb88292 100644 --- a/controller/internal/backup/backup.go +++ b/controller/internal/backup/backup.go @@ -25,6 +25,14 @@ import ( // moved out of the controller into the host agent (slice 8C). This Manager now // only owns the app-data domain. type Manager struct { + // R-897: when this controller started, and the seams of the post-boot drive wait (driveready.go). Zero + // startedAt = no wait (a Manager built outside NewManager, e.g. a test that does not ask for it). + startedAt time.Time + driveLive func(root string) bool + driveWaitPoll func(time.Duration) + nowFn func() time.Time + driveWarned map[string]bool + driveMu sync.Mutex // its own lock: the capture sweep may run while m.mu is held elsewhere cfg *config.Config logger *log.Logger settings *settings.Settings @@ -370,6 +378,7 @@ func NewManager(cfg *config.Config, sett *settings.Settings, logger *log.Logger) logger: logger, settings: sett, systemDataPath: cfg.Paths.SystemDataPath, + startedAt: time.Now(), } // R-166: its OWN file next to quiesce-state.json, never inside it — one file, one writer. m.appStop = NewAppStopGuard(filepath.Join(cfg.Paths.DataDir, "appstop-state.json"), logger) diff --git a/controller/internal/backup/driveready.go b/controller/internal/backup/driveready.go new file mode 100644 index 0000000..09141bb --- /dev/null +++ b/controller/internal/backup/driveready.go @@ -0,0 +1,103 @@ +package backup + +import ( + "os" + "strings" + "time" +) + +// R-897 (2026-10-07): after a host restart the agent binds each drive under /mnt/felhom-drives, and when the guest +// started after that first bind it NORMALIZES it once more (umount + mount, felhom-agent localapi/intermediary.go). A +// recovery-unit capture that ran in that second failed — `mkdir /mnt/felhom-drives/hdd_1/backups: permission +// denied` — and the operator got a backup failure for a healthy app. The kernel lane restarts boxes at night, so this +// would have come after every kernel step. +// +// The rule: for DriveWaitWindow after the controller starts, a capture for an app on a drive runs only once that +// drive's bind is LIVE in this process's mount namespace (the same signal the startup app gate uses, +// web/intermediary.go driveBindLive). A periodic refresh skips the app until then (it runs every 5 minutes anyway); +// a data run waits for it. After the window the capture runs whatever the bind says, and says so once at WARN. The +// agent's bind order is unchanged. Pinned by driveready_test.go. + +// DriveWaitWindow is how long after the controller starts a capture waits for a drive's bind. +const DriveWaitWindow = 10 * time.Minute + +const drivesParent = "/mnt/felhom-drives/" + +// driveRootOf is "/mnt/felhom-drives/" for a path under it, "" for any other path (the system-data SSD). +func driveRootOf(p string) string { + if !strings.HasPrefix(p, drivesParent) { + return "" + } + name := strings.SplitN(strings.TrimPrefix(p, drivesParent), "/", 2)[0] + if name == "" { + return "" + } + return drivesParent + name +} + +// mountinfoHasTarget reports whether root is a mount target in this process's own mount namespace. +func mountinfoHasTarget(root string) bool { + data, err := os.ReadFile("/proc/self/mountinfo") + if err != nil { + return false + } + for _, line := range strings.Split(string(data), "\n") { + if f := strings.Fields(line); len(f) >= 5 && f[4] == root { + return true + } + } + return false +} + +func (m *Manager) now() time.Time { + if m.nowFn != nil { + return m.nowFn() + } + return time.Now() +} + +// driveReady says whether a capture for an app at drivePath may run now (true outside the post-boot window, for a +// non-drive path, or once the bind is live). dataRun: wait (poll) for the bind until the window ends instead of +// skipping. +func (m *Manager) driveReady(drivePath string, dataRun bool) bool { + root := driveRootOf(drivePath) + if root == "" || m.startedAt.IsZero() { + return true + } + live := m.driveLive + if live == nil { + live = mountinfoHasTarget + } + deadline := m.startedAt.Add(DriveWaitWindow) + for { + if live(root) { + return true + } + if !m.now().Before(deadline) { + m.driveMu.Lock() + warned := m.driveWarned[root] + if m.driveWarned == nil { + m.driveWarned = map[string]bool{} + } + m.driveWarned[root] = true + m.driveMu.Unlock() + if !warned { + m.logger.Printf("[WARN] [backup] %s is still not bound live %s after the controller started — capturing anyway (R-897)", + root, DriveWaitWindow) + } + return true + } + if !dataRun { + if m.isDebug() { + m.logger.Printf("[DEBUG] [backup] recovery-unit refresh waits for %s — its bind is not live yet after the start (R-897)", root) + } + return false + } + sleep := m.driveWaitPoll + if sleep == nil { + sleep = time.Sleep + } + m.logger.Printf("[INFO] [backup] waiting for %s to be bound live before the capture (post-boot, R-897)", root) + sleep(5 * time.Second) + } +} diff --git a/controller/internal/backup/driveready_test.go b/controller/internal/backup/driveready_test.go new file mode 100644 index 0000000..e9f940e --- /dev/null +++ b/controller/internal/backup/driveready_test.go @@ -0,0 +1,78 @@ +package backup + +import ( + "testing" + "time" +) + +// drivePathProvider puts every app on /mnt/felhom-drives/hdd_1 (the measured R-897 case). +type drivePathProvider struct{ unitFailProvider } + +func (p *drivePathProvider) GetStackHDDPath(string) string { return "/mnt/felhom-drives/hdd_1" } + +// R-897: right after a boot, a capture for an app on a drive waits until the drive's bind is LIVE. The drive reads +// not-bound, then bound → the capture (here a capture that fails, so it is visible as a unit event) starts only after. +// COMPANION RED-PROOF (observed): remove the driveReady call in captureAllRecoveryUnits → "captured while the drive +// was not bound". +func TestDriveReady_RefreshWaitsForTheBindThenCaptures(t *testing.T) { + m, got := newUnitNotifyManager(t, []string{"calibre-web"}, map[string]bool{"calibre-web": true}) + base := m.stackProvider.(*unitFailProvider) + m.stackProvider = &drivePathProvider{*base} + now := time.Date(2026, 10, 7, 15, 16, 28, 0, time.UTC) + m.startedAt, m.nowFn = now.Add(-20*time.Second), func() time.Time { return now } + bound := false + var asked []string + m.driveLive = func(root string) bool { asked = append(asked, root); return bound } + + m.captureAllRecoveryUnits(false) + if len(*got) != 0 { + t.Fatalf("captured while the drive was not bound: %+v", *got) + } + if len(asked) == 0 || asked[0] != "/mnt/felhom-drives/hdd_1" { + t.Fatalf("the drive root asked = %v", asked) + } + bound = true + m.captureAllRecoveryUnits(false) + if len(*got) != 1 { + t.Fatalf("after the bind the capture must run: %+v", *got) + } +} + +// After the window the capture runs whatever the bind says (and says so). +func TestDriveReady_AfterTheWindowItRunsAnyway(t *testing.T) { + m, got := newUnitNotifyManager(t, []string{"calibre-web"}, map[string]bool{"calibre-web": true}) + base := m.stackProvider.(*unitFailProvider) + m.stackProvider = &drivePathProvider{*base} + now := time.Date(2026, 10, 7, 15, 30, 0, 0, time.UTC) + m.startedAt, m.nowFn = now.Add(-DriveWaitWindow), func() time.Time { return now } + m.driveLive = func(string) bool { return false } + m.captureAllRecoveryUnits(false) + if len(*got) != 1 { + t.Fatalf("after %s the capture must run anyway: %+v", DriveWaitWindow, *got) + } +} + +// A data run WAITS (polls) instead of skipping; a non-drive path and a Manager without a start time never wait. +func TestDriveReady_DataRunPollsAndOthersNeverWait(t *testing.T) { + m, _ := newUnitNotifyManager(t, nil, nil) + now := time.Date(2026, 10, 7, 15, 16, 28, 0, time.UTC) + m.startedAt, m.nowFn = now, func() time.Time { return now } + n := 0 + m.driveLive = func(string) bool { n++; return n >= 3 } + polls := 0 + m.driveWaitPoll = func(d time.Duration) { polls++; now = now.Add(d) } + if !m.driveReady("/mnt/felhom-drives/hdd_1/x", true) || polls != 2 { + t.Fatalf("data run: polls=%d", polls) + } + if !m.driveReady("/var/lib/felhom/system-data", false) { + t.Fatal("the system SSD never waits") + } + m2, _ := newUnitNotifyManager(t, nil, nil) + m2.driveLive = func(string) bool { return false } + if !m2.driveReady("/mnt/felhom-drives/hdd_1", false) { + t.Fatal("no start time → no wait") + } + if driveRootOf("/mnt/felhom-drives/") != "" || driveRootOf("/mnt/felhom-drives/hdd_2/a/b") != "/mnt/felhom-drives/hdd_2" { + t.Fatal("driveRootOf") + } +} diff --git a/controller/internal/backup/recovery_unit.go b/controller/internal/backup/recovery_unit.go index 9992f5d..cf5ca8e 100644 --- a/controller/internal/backup/recovery_unit.go +++ b/controller/internal/backup/recovery_unit.go @@ -450,6 +450,11 @@ func (m *Manager) captureAllRecoveryUnits(dataRun bool) { if m.settings != nil && (m.settings.IsDisconnected(drivePath) || m.settings.IsDecommissioned(drivePath)) { continue // drive not writable — skip, the existing unit stays as-is } + // R-897: right after a boot the agent may still be (re)binding the drive; a capture in that second failed + // with "permission denied" (measured on demo-hp 2026-10-07). Wait for the bind — bounded (driveready.go). + if !m.driveReady(drivePath, dataRun) { + continue + } // Slice 4: a HELD app's unit is its RESTORE POINT, and the hold text names that copy's date. // Re-capturing it would write the definition the app is held ON (after a failed update: the new // version that would not start) into the unit, and the next Tier-2 run would mirror it over the