From 9d9e4041c91a8b1ba754f7e26009f7efc46271a2 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Thu, 22 Oct 2026 22:45:42 +0200 Subject: [PATCH] Second review of the night's own code: a stray clears when a later removal works (N2), the start-up check never removes this process's own copy (N3), one copy per destination at a time (N4), RunTier2 refuses during a restore for every caller (N5), the import refusal no longer advises removal (N9); red-proved, race-clean; README; REPORT; unreleased --- CHANGELOG.md | 11 +- REPORT.md | 67 ++++--- controller/README.md | 8 + controller/internal/appexport/restore.go | 5 +- .../r1180_mirror_during_restore_test.go | 22 +++ .../internal/backup/r1214_capped_copy_test.go | 2 + controller/internal/backup/tier2.go | 12 ++ .../internal/backup/tier2_copy_lifecycle.go | 173 +++++++++++++++--- .../backup/tier2_copy_lifecycle_test.go | 103 ++++++++++- 9 files changed, 341 insertions(+), 62 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4ab850f..db2b5a7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,7 +21,16 @@ text now fits an app that runs but is unhealthy or restarting (IsStackRunning counts only running/degraded) — „leállt, vagy hibásan indul … ha hibásan fut, távolítsd el"; the import path for those states stays a row (R-1187). C6: two main.go comments no longer say a box off at 05:30–06:00 always gets the proof made up (only with a missed backup leg). - C8: README — `backup.volumes` excluded leaves the app-data backups, not the `.fab` export or the whole-guest snapshot. Tests `TestStrayCopy_*` (backup, web, + C8: README — `backup.volumes` excluded leaves the app-data backups, not the `.fab` export or the whole-guest snapshot. +- **A second fresh review of the same night's own code (N2–N5, N9).** N2: a container whose removal failed is a + per-name stray, cleared when a later removal works (it used to refuse every restore until a restart). N3: the start-up + check never removes a copy THIS process runs (`running` names). N4: one copy per destination at a time in a process — + a second run (the household's „Tier 2 on" save, the debug run) waits instead of removing the first's container. N5: + `RunTier2` itself refuses during a restore of that app (R-1180 for every caller, not only the night loop). One + background retry for strays and a failed start-up check; tests switch it off (`tier2RetryOff` — a timer outliving a test + would reach the host's real Docker). N9: the R-1187 (c) refusal no longer advises removing an unhealthy app (its data + may be newer than the bundle) — „kérd az üzemeltető segítségét". Tests `TestStrayCopy_AStrayClears…`, `…KeepsThis + ProcessesOwnCopy`, `…SameDestinationWaits`, `TestR1180_ADirectRunTier2…`, each red-proved; `-race` clean. Tests `TestStrayCopy_*` (backup, web, wiring; Docker-free seams), each red-proved; 9202 proof in felhom.eu `audits/night-2026-10-23/P1-straycopy/`. ## Unreleased — the second-drive copy no longer squeezes the apps' memory (R-1214), 2026-10-22 night diff --git a/REPORT.md b/REPORT.md index a56f970..3d48a1d 100644 --- a/REPORT.md +++ b/REPORT.md @@ -1,30 +1,41 @@ -# REPORT — night 2026-10-22: four fixes on `main`, not released +# REPORT — night 2026-10-22 → 23: the stray-copy fix and the review fixes, nothing released -**What:** the night brief's controller parts. Nothing released (the brief forbids a controller release tonight). -Design read: `07-backup-architecture.md` §6.1.1 (catch-up), §6.2 (capture set), §10.2; `09` §6.5 (drill catalog). -Next release **0.340.0**, **MinAgent 0.158.1** (unchanged). +**What:** the night brief's controller parts (Part 1, the controller findings of Part 3). No release, no floor change. +Design read: `07-backup-architecture.md` §6.3, §8 (R-1180's guard), now §8.2b. -- **R-49 (operator D21 = B), `6a17c95`.** `.felhom.yml` `backup.volumes: [{name, class: excluded}]` leaves a named - volume out of every backup (`appbackup.ExcludedDockerVolumes` → `backup.Manager.dumpableVolumes`); declared names - only, a list that would exclude every named volume is refused whole. Red-proved (`TestR49_*`, both packages) and - the R-591 deep-copy alias test caught a shared slice (fixed in `deepCopyStack`). 9202: Immich unit - 1 160 553 832 → 336 788 031 B; with the cache volume removed Immich's ML answered after 9.2 s. -- **R-1187 (c), `d5f88a2`.** A `.fab` import over an installed app that is not running merged the old volume data with - the bundle's. Reproduced on 9202 rc.1 (a marker written after the export survived the import; the running control - replaced it); now refused with a Hungarian sentence, the app untouched (rc.2: markers unchanged; the running path - still replaces). Red-proved (`r1187c_test.go`). Evidence felhom.eu `audits/night-2026-10-22/P3-candidates/r1187c-9202.txt`. -- **R-1189 (d), `d5f88a2`.** The off-site proof (05:30) and integrity check (06:00) never ran on a box that is off - then. `nightchain.CatchUp.After` now runs both once after the catch-up's legs; the false comment in `main.go` - corrected. Red-proved (`nightchain/r1189d_test.go`, `cmd/controller/r1189d_wiring_test.go`). -- **R-1214, `03c0a69` + `ae39467`.** The 03:30 second-drive copy's page cache pushed the apps out of memory. - `rsyncMirror` runs rsync in a 512 MB memory-capped container of the controller's own image, only for clean `/mnt/` - paths with no symlink (a security review found the symlink case; fixed and tested). 9202 (4 GB, 1.8 GB held, 6 GB): - full stall 5.7 / 2.5 s → 0.37 / 0.32 s; peak „full" 16.8 / 6.9 % → 0.9 / 1.0 %. A real `POST /api/backup/tier2` on - rc.4: 6 capped containers, each exit 0; Immich's copy equals its source (0 differences, 44 = 44 files). - `docker_run_volume_path_gate.py` allow-list entry with its WHY. -- **Gates:** `controller_gates.py --fast` green before each push; CI by commit — see felhom.eu - `REPORT-night-2026-10-22.md`. -- **Teardown (9202):** throwaway uptime-kuma removed through the product (`.fab` deleted); hog container and 19 GB of - test files removed; memory 25898 MB / swap 512 MB again; Immich's `.felhom.yml` back to its pre-night file; controller - back on **0.339.0** (healthy); the drill catalog equals live main again. Host: `/tmp/r1214*` removed on demo-hp. Hub: - 9202 has no hub link — nothing. +## Part 1 — the stray-copy fix (`66a69d4`, `912e592`) + +The capped second-drive copy (R-1214) runs `rsync -a --delete` in its own container. A timeout, a controller restart +or a self-update killed only the `docker` CLI — the container went on deleting, outside every guard the controller +holds. Now: +- each copy container has a fixed name (`felhom-tier2-copy--<8 hex>`) and the label `felhom.tier2-copy=1`; +- a leftover of the same copy is removed before a new one starts; on any error, the timeout included, it is removed by + name; +- at start, BEFORE the scheduler and the web server, every labelled container is removed (each logged; retried every + minute until it succeeds; restores refused meanwhile); +- a restore is refused while any second-drive copy runs or a leftover may run; +- review C4/C7 in the same function: `--mount` (a path the daemon does not see is refused instead of created empty), + the controller's image ID with `--pull never`; `--no-healthcheck` (the 9202 proof showed the inherited health check). + +**Tests** (Docker-free seams): `TestStrayCopy_*` — 8 in `internal/backup`, 1 web, 1 wiring; each seen failing with its +mechanism removed. **9202 proof** (felhom.eu `audits/night-2026-10-23/P1-straycopy/`): rc.5; a controller restart in +the middle of a 16 GB copy → the new controller removed `felhom-tier2-copy-immich-948f2280` at start; a restore probe +during the copy was refused; the redone copy equals the source (54 s); a 15 s test build (rc.5 + a binary with the +limit set by ldflags, never pushed) → the timed-out container removed, the partial copy stopped growing. 9202 back on +0.339.0, test files and the test image removed. + +## Part 3 — review findings (controller), verified at file:line + +| # | Finding | Verdict | +|---|---|---| +| C1 | the copy container outlives the CLI | REAL → fixed (Part 1) | +| C2 | two more import paths merge old and new data | REAL, pre-existing in 0.339.0 → R-1187 (recovery code: red-proof + 9202 proof first); not a hold | +| C3 | the R-1187 (c) refusal also catches an unhealthy app, with wrong advice | REAL → text fixed (`943c517`); the import path → R-1187 | +| C4 | `-v` creates a missing path on the daemon side | REAL → `--mount` (`66a69d4`) | +| C5 | the catch-up holds the whole-guest backup while its slow checks run | REAL → fixed (`943c517`, `TestC5_*`, red-proved) | +| C6 | two comments overstate the proof's catch-up | REAL → fixed | +| C7 | the image tag, not its ID; no `--pull never` | REAL → fixed; „no memory cgroup → uncapped": NOT-A-FINDING (every Felhom guest is an LXC on a cgroup-v2 Proxmox kernel; the guest's own memory figures come from it) | +| C8 | README: „out of every backup" | REAL → fixed (the `.fab` export and the whole-guest snapshot still hold it) | + +**Images:** `0.340.0-rc.5` (= `66a69d4`), `0.340.0-rc.6` (= `943c517`, on tonight's test box). CI: `66a69d4` 2227, +`912e592` 2228 green; `943c517` and the docs commit: see felhom.eu `REPORT-night-2026-10-23.md`. diff --git a/controller/README.md b/controller/README.md index c66de56..3bfcbbf 100644 --- a/controller/README.md +++ b/controller/README.md @@ -1399,6 +1399,14 @@ retired in v0.126.0 when the moved blocks were legitimately rewritten onto the s contain no symlink (`tier2CappedPath`, `filepath.EvalSymlinks(p) == p`: a link could point the mount elsewhere). A docker start error (exit 125) falls back to plain rsync; any other failure is returned. Measured on 9202 (4 GB, 1.8 GB held, 6 GB copy): full stall 5.7 s → 0.37 s. Tests `r1214_capped_copy_test.go`. +- **The copy container never outlives the copy (the stray-copy fix, unreleased, rides 0.340.0).** Each copy container has + a fixed name (`felhom-tier2-copy--<8 hex of the destination>`) and the label `felhom.tier2-copy=1`; a leftover of + the same copy is removed before it starts, and on any error — the timeout included — it is removed by name. At + controller start, BEFORE the scheduler and the web server, every labelled container is removed (logged; retried every + minute until it succeeds). A restore is refused while any second-drive copy runs or a leftover may run + (`backup.Tier2CopyBlocksRestore` → `restoreOpBlocked`). The run uses `--mount` (a path the daemon does not see is + refused, exit 125 → the in-process copy), the controller's image ID with `--pull never`, and `--no-healthcheck`. + Tests `tier2_copy_lifecycle_test.go`, `web/straycopy_restore_refused_test.go`, `cmd/controller/straycopy_wiring_test.go`. - **A template may leave a named volume out of the app-data backups (unreleased, rides 0.340.0; R-49, operator D21 = B).** `.felhom.yml` `backup.volumes: [{name: , class: excluded}]` — every named volume is dumped except `_` (`appbackup.ExcludedDockerVolumes` → `backup.Manager.dumpableVolumes`), so it leaves Tier 1, Tier 2 diff --git a/controller/internal/appexport/restore.go b/controller/internal/appexport/restore.go index 04781fb..ff923fe 100644 --- a/controller/internal/appexport/restore.go +++ b/controller/internal/appexport/restore.go @@ -364,11 +364,12 @@ func (e *Exporter) executeImport(req ImportRequest, job *Job) { // is a corruption shape), reported as success. Only a running app's volumes are removed first. So this import is // refused here, before anything is written; the household starts the app (or removes it) and imports again. „Not // running" is IsStackRunning's view: running or degraded only, so an unhealthy or restarting app is refused too — - // the text says so and names removal (review 2026-10-22 night, C3; the import path for those states is R-1187). + // the text says so; it does NOT advise removal, which would lose data newer than the bundle (review 2026-10-23 + // night, C3 + N9; the import path for those states is R-1187). // Pinned by TestR1187c_AStoppedAppIsNotImportedOver. if isDeployed && !isRunning { e.logger.Printf("[WARN] Import: refused — %s is installed but not running; importing over it would merge the old data with the bundle's (R-1187 c)", manifest.AppName) - e.failJob(job, step, "Az alkalmazás telepítve van, de nem fut rendben (leállt, vagy hibásan indul), ezért a csomagot nem töltjük vissza: a régi adatai összekeveredhetnének a csomagéval. Az alkalmazás érintetlen. Ha leállt, indítsd el; ha hibásan fut, távolítsd el. Utána próbáld újra.") + e.failJob(job, step, "Az alkalmazás telepítve van, de nem fut rendben (leállt, vagy hibásan indul), ezért a csomagot nem töltjük vissza: a régi adatai összekeveredhetnének a csomagéval. Az alkalmazás érintetlen. Ha leállt, indítsd el, és próbáld újra; ha hibásan fut, kérd az üzemeltető segítségét — ne távolítsd el, mert az adatai a csomagnál újabbak lehetnek.") return } diff --git a/controller/internal/backup/r1180_mirror_during_restore_test.go b/controller/internal/backup/r1180_mirror_during_restore_test.go index ad3761a..c5d41eb 100644 --- a/controller/internal/backup/r1180_mirror_during_restore_test.go +++ b/controller/internal/backup/r1180_mirror_during_restore_test.go @@ -58,3 +58,25 @@ func TestR1180_TheNightMirrorNeverRunsDuringARestoreOfThatApp(t *testing.T) { t.Fatalf("after the restore the mirror must run again, got %v", got) } } + +// Review 2026-10-23 night, N5: RunTier2 itself refuses during a restore of that app — the config-save and debug paths +// call it directly. RED-PROOF: with the restoreRunningFor check at the top of RunTier2 removed, this fails — seen +// failing 2026-10-23 night. +func TestR1180_ADirectRunTier2NeverRunsDuringARestore(t *testing.T) { + m, src, target, prov := newTier2V2(t, "app") + prov.has["app"] = true + prov.binds["app"] = []ClassifiedBind{mHDD("appdata/app/photos")} + m.stackProvider = r1180Provider{prov} + called := 0 + m.tier2Mirror = func(s, d string) error { called++; return rsyncMirror(s, d) } + mustWrite(t, filepath.Join(src, "appdata", "app", "photos", "a.jpg"), "a") + m.BeginRestoreOp("tier2-whole-restore", "app") + if err := m.RunTier2("app"); err != nil || called != 0 { + t.Fatalf("a direct run during a restore must copy nothing (err %v, mirror calls %d)", err, called) + } + m.EndRestoreOp(true, "") + if err := m.RunTier2("app"); err != nil || called == 0 { + t.Fatalf("after the restore the direct run must mirror (err %v, calls %d)", err, called) + } + _ = target +} diff --git a/controller/internal/backup/r1214_capped_copy_test.go b/controller/internal/backup/r1214_capped_copy_test.go index 8dedbd9..492a5cc 100644 --- a/controller/internal/backup/r1214_capped_copy_test.go +++ b/controller/internal/backup/r1214_capped_copy_test.go @@ -23,6 +23,7 @@ func withSeams(t *testing.T, root string, img string, run func(args []string) ([ oldRoot, oldImg, oldRun, oldLog, oldDocker := tier2CappedRoot, tier2SelfImage, tier2RunCapped, tier2Logf, tier2Docker // The copy's lifecycle commands (rm -f by name) never reach Docker from a test (they would act on the host). tier2Docker = func(context.Context, ...string) ([]byte, error) { return nil, nil } + tier2RetryOff = true tier2CappedRoot = root tier2SelfImage = func() string { return img } tier2RunCapped = func(_ context.Context, args []string) ([]byte, int, error) { @@ -32,6 +33,7 @@ func withSeams(t *testing.T, root string, img string, run func(args []string) ([ tier2Logf = func(string, ...any) {} t.Cleanup(func() { tier2CappedRoot, tier2SelfImage, tier2RunCapped, tier2Logf, tier2Docker = oldRoot, oldImg, oldRun, oldLog, oldDocker + tier2RetryOff = false }) return rec } diff --git a/controller/internal/backup/tier2.go b/controller/internal/backup/tier2.go index 2c2db7c..ddf6be1 100644 --- a/controller/internal/backup/tier2.go +++ b/controller/internal/backup/tier2.go @@ -340,6 +340,12 @@ func (m *Manager) tier2ReconcileRoots(destBase string, roots, legRels []string) // capture legs (§8). Best-effort and idempotent. Records status for the UI; returns an error only on // an actual copy failure (no valid target is a recorded status, not an error). func (m *Manager) RunTier2(stackName string) error { + // R-1180 for EVERY caller (review 2026-10-23 night, N5): the household's „Tier 2 on" save and the debug run call + // this directly, outside RunAllTier2's skip — a mirror (rsync --delete) must never start during a restore of the app. + if m.restoreRunningFor(stackName) { + m.logger.Printf("[WARN] [backup] Tier 2 for %s not started — a restore of it is running; it is mirrored at the next run (R-1180)", stackName) + return nil + } // Customer turned Tier 2 off for this app (config panel) — skip without touching status. if m.settings != nil { if cd := m.settings.GetCrossDriveConfig(stackName); cd != nil && cd.UserDisabled { @@ -797,6 +803,10 @@ func rsyncMirror(src, dst string) error { s, d := strings.TrimRight(src, "/"), strings.TrimRight(dst, "/") rs := []string{"-a", "--delete", s + "/", d + "/"} name, app := tier2CopyName(d) + // One copy per destination at a time in this process (review N4): a second run waits, it never removes the first. + lk := tier2CopyLock(name) + lk.Lock() + defer lk.Unlock() tier2CopyBegin(app) defer tier2CopyEnd(app) if tier2CappedPath(s) && tier2CappedPath(d) { @@ -813,7 +823,9 @@ func rsyncMirror(src, dst string) error { // created empty — an empty source would let `--delete` empty the copy (review 2026-10-22 night, C4). "--mount", "type=bind,src=" + s + ",dst=" + s + ",readonly", "--mount", "type=bind,src=" + d + ",dst=" + d, "--entrypoint", "rsync", img}, rs...) + tier2MarkRunning(name, true) // the start-up retry never removes a copy this process runs (review N3) out, code, err := tier2RunCapped(ctx, args) + tier2MarkRunning(name, false) if err == nil { return nil } diff --git a/controller/internal/backup/tier2_copy_lifecycle.go b/controller/internal/backup/tier2_copy_lifecycle.go index 0fecdc6..96f7dbd 100644 --- a/controller/internal/backup/tier2_copy_lifecycle.go +++ b/controller/internal/backup/tier2_copy_lifecycle.go @@ -87,11 +87,39 @@ var tier2Docker = func(ctx context.Context, args ...string) ([]byte, error) { } // The controller's own record of copies (package-level: one controller, one backup manager per process). +// - inFlight: app → copies running now (capped or in-process); +// - running: the container names THIS process runs now — the start-up check never removes one of them; +// - strays: names whose removal failed — cleared when a later removal of that name works; +// - startupPending: the start-up check has not succeeded yet. +// +// Restores are refused while any of these is non-empty (review 2026-10-23 night, N2/N3: a stray used to block every +// restore until a restart, and the start-up retry used to remove this process's own running copies). var tier2Copies = struct { sync.Mutex - inFlight map[string]int // app → copies running now (capped or in-process) - stray bool // a container this process could not remove may still run, or the start-up removal has not succeeded -}{inFlight: map[string]int{}} + inFlight map[string]int + running map[string]bool + strays map[string]bool + startupPending bool + retrying bool +}{inFlight: map[string]int{}, running: map[string]bool{}, strays: map[string]bool{}} + +// tier2CopyLocks serializes copies into the SAME destination within this process (review N4): a second run waits for +// the first instead of removing its container by name (which killed it mid-copy and mailed a false failure). +var tier2CopyLocks = struct { + sync.Mutex + m map[string]*sync.Mutex +}{m: map[string]*sync.Mutex{}} + +func tier2CopyLock(name string) *sync.Mutex { + tier2CopyLocks.Lock() + defer tier2CopyLocks.Unlock() + l := tier2CopyLocks.m[name] + if l == nil { + l = &sync.Mutex{} + tier2CopyLocks.m[name] = l + } + return l +} func tier2CopyBegin(app string) { tier2Copies.Lock() @@ -107,55 +135,131 @@ func tier2CopyEnd(app string) { tier2Copies.Unlock() } -func tier2SetStray(v bool) { +func tier2MarkRunning(name string, on bool) { tier2Copies.Lock() - tier2Copies.stray = v + if on { + tier2Copies.running[name] = true + } else { + delete(tier2Copies.running, name) + } tier2Copies.Unlock() } // tier2RemoveCopy removes the copy container `name` (no error when it does not exist). It reports whether the -// container is surely gone; when not, the stray flag is set, so restores stay refused until a removal succeeds. +// container is surely gone; when not, the name is recorded as a stray (restores refused) and retried every minute. func tier2RemoveCopy(name, why string) bool { ctx, cancel := context.WithTimeout(context.Background(), 60*time.Second) defer cancel() out, err := tier2Docker(ctx, "rm", "-f", name) if err != nil && !strings.Contains(strings.ToLower(string(out)), "no such container") { - tier2Logf("[ERROR] [tier2] could not remove the copy container %s (%s): %v %s — restores stay refused until it is removed", + tier2Logf("[ERROR] [tier2] could not remove the copy container %s (%s): %v %s — restores stay refused until it is removed (retried every minute)", name, why, err, strings.TrimSpace(string(out))) - tier2SetStray(true) + tier2Copies.Lock() + tier2Copies.strays[name] = true + tier2Copies.Unlock() + tier2StartRetry(context.Background()) return false } + tier2Copies.Lock() + delete(tier2Copies.strays, name) + tier2Copies.Unlock() return true } -// ClearLeftoverTier2Copies removes every labelled copy container — a copy a previous controller process started and -// lost (restart, self-update, crash). It runs at controller start, BEFORE the scheduler and the web server; each -// removal is logged. Until it succeeds, restores are refused; on failure it retries every minute in the background -// until it succeeds or ctx ends. -func ClearLeftoverTier2Copies(ctx context.Context) error { - tier2SetStray(true) - err := clearLeftoverTier2CopiesOnce(ctx) - if err == nil { - tier2SetStray(false) - return nil +// tier2RetryEvery is the retry period for strays and a failed start-up check; tier2RetryOff (tests only) keeps the +// background retry from starting at all — a timer that outlives a test would reach the real Docker of the host. +var ( + tier2RetryEvery = time.Minute + tier2RetryOff = false +) + +// tier2StartRetry starts ONE background retry (if none runs): every tier2RetryEvery it redoes a failed start-up check +// and the removal of every stray, and ends when nothing is left or ctx ends. +func tier2StartRetry(ctx context.Context) { + tier2Copies.Lock() + if tier2Copies.retrying || tier2RetryOff { + tier2Copies.Unlock() + return } - tier2Logf("[ERROR] [tier2] the start-up check for a leftover second-drive copy failed: %v — restores are refused until it succeeds; retrying every minute", err) + tier2Copies.retrying = true + tier2Copies.Unlock() + every := tier2RetryEvery go func() { - t := time.NewTicker(time.Minute) + t := time.NewTicker(every) defer t.Stop() for { select { case <-ctx.Done(): + tier2Copies.Lock() + tier2Copies.retrying = false + tier2Copies.Unlock() return case <-t.C: - if clearLeftoverTier2CopiesOnce(ctx) == nil { - tier2SetStray(false) - tier2Logf("[INFO] [tier2] the leftover second-drive copy check succeeded — restores allowed again") - return - } + } + if tier2RetryOnce(ctx) { + tier2Logf("[INFO] [tier2] no leftover or stray second-drive copy container is left — restores allowed again") + return } } }() +} + +// tier2RetryOnce does one retry round; it reports (and clears `retrying`) when nothing is left to retry. +func tier2RetryOnce(ctx context.Context) bool { + tier2Copies.Lock() + pending := tier2Copies.startupPending + var names []string + for n := range tier2Copies.strays { + names = append(names, n) + } + tier2Copies.Unlock() + if pending && clearLeftoverTier2CopiesOnce(ctx) == nil { + tier2Copies.Lock() + tier2Copies.startupPending = false + tier2Copies.Unlock() + } + for _, n := range names { + tier2RemoveCopyQuiet(ctx, n) + } + tier2Copies.Lock() + defer tier2Copies.Unlock() + if !tier2Copies.startupPending && len(tier2Copies.strays) == 0 { + tier2Copies.retrying = false + return true + } + return false +} + +// tier2RemoveCopyQuiet is the retry's removal: a failure keeps the stray without starting another retry. +func tier2RemoveCopyQuiet(ctx context.Context, name string) { + rctx, cancel := context.WithTimeout(ctx, 60*time.Second) + defer cancel() + out, err := tier2Docker(rctx, "rm", "-f", name) + if err != nil && !strings.Contains(strings.ToLower(string(out)), "no such container") { + return + } + tier2Copies.Lock() + delete(tier2Copies.strays, name) + tier2Copies.Unlock() + tier2Logf("[INFO] [tier2] the stray copy container %s is removed", name) +} + +// ClearLeftoverTier2Copies removes every labelled copy container a previous controller process started and lost +// (restart, self-update, crash). It runs at controller start, BEFORE the scheduler and the web server; each removal is +// logged. Until it succeeds, restores are refused; on failure it is retried every minute in the background. +func ClearLeftoverTier2Copies(ctx context.Context) error { + tier2Copies.Lock() + tier2Copies.startupPending = true + tier2Copies.Unlock() + err := clearLeftoverTier2CopiesOnce(ctx) + if err == nil { + tier2Copies.Lock() + tier2Copies.startupPending = false + tier2Copies.Unlock() + return nil + } + tier2Logf("[ERROR] [tier2] the start-up check for a leftover second-drive copy failed: %v — restores are refused until it succeeds; retrying every minute", err) + tier2StartRetry(ctx) return err } @@ -166,7 +270,14 @@ func clearLeftoverTier2CopiesOnce(ctx context.Context) error { if err != nil { return fmt.Errorf("docker ps: %v %s", err, strings.TrimSpace(string(out))) } - names := strings.Fields(string(out)) + var names []string + tier2Copies.Lock() + for _, n := range strings.Fields(string(out)) { + if !tier2Copies.running[n] { // never a copy THIS process runs (review N3) + names = append(names, n) + } + } + tier2Copies.Unlock() if len(names) == 0 { tier2Logf("[INFO] [tier2] start-up: no leftover second-drive copy container") return nil @@ -195,7 +306,7 @@ func clearLeftoverTier2CopiesOnce(ctx context.Context) error { func (m *Manager) Tier2CopyBlocksRestore() (app string, blocked bool) { tier2Copies.Lock() defer tier2Copies.Unlock() - if tier2Copies.stray { + if tier2Copies.startupPending || len(tier2Copies.strays) > 0 { return "", true } for a := range tier2Copies.inFlight { @@ -204,6 +315,14 @@ func (m *Manager) Tier2CopyBlocksRestore() (app string, blocked bool) { return "", false } +// tier2ResetForTest empties the record (tests only). +func tier2ResetForTest() { + tier2Copies.Lock() + tier2Copies.inFlight, tier2Copies.running, tier2Copies.strays = map[string]int{}, map[string]bool{}, map[string]bool{} + tier2Copies.startupPending, tier2Copies.retrying = false, false + tier2Copies.Unlock() +} + // MarkTier2CopyForTest records a copy of app as running until the returned func is called — a test-only seam (another // package's test exercises the restore refusal without a real copy), in the spirit of AcquireRunningForTest. func MarkTier2CopyForTest(app string) func() { diff --git a/controller/internal/backup/tier2_copy_lifecycle_test.go b/controller/internal/backup/tier2_copy_lifecycle_test.go index 3712533..ae8e70f 100644 --- a/controller/internal/backup/tier2_copy_lifecycle_test.go +++ b/controller/internal/backup/tier2_copy_lifecycle_test.go @@ -33,7 +33,9 @@ func strayCopySeams(t *testing.T, root string, run func(ctx context.Context, arg fn func(args []string) ([]byte, error)) (*dockerRec, *dockerRec) { t.Helper() runs, lifecycle := &dockerRec{}, &dockerRec{} - oldRoot, oldImg, oldRun, oldLog, oldDocker, oldTO := tier2CappedRoot, tier2SelfImage, tier2RunCapped, tier2Logf, tier2Docker, tier2CopyTimeout + oldRoot, oldImg, oldRun, oldLog, oldDocker, oldTO, oldRetry := tier2CappedRoot, tier2SelfImage, tier2RunCapped, tier2Logf, tier2Docker, tier2CopyTimeout, tier2RetryEvery + tier2RetryEvery = time.Hour + tier2RetryOff = true // the background retry never starts in a test (it would reach the real Docker later) tier2CappedRoot = root tier2SelfImage = func() string { return "sha256:abc" } tier2RunCapped = func(ctx context.Context, args []string) ([]byte, int, error) { @@ -49,10 +51,11 @@ func strayCopySeams(t *testing.T, root string, run func(ctx context.Context, arg return fn(args) } tier2Logf = func(string, ...any) {} - tier2SetStray(false) + tier2ResetForTest() t.Cleanup(func() { - tier2CappedRoot, tier2SelfImage, tier2RunCapped, tier2Logf, tier2Docker, tier2CopyTimeout = oldRoot, oldImg, oldRun, oldLog, oldDocker, oldTO - tier2SetStray(false) + tier2CappedRoot, tier2SelfImage, tier2RunCapped, tier2Logf, tier2Docker, tier2CopyTimeout, tier2RetryEvery = oldRoot, oldImg, oldRun, oldLog, oldDocker, oldTO, oldRetry + tier2RetryOff = false + tier2ResetForTest() }) return runs, lifecycle } @@ -210,3 +213,95 @@ func TestStrayCopy_ARestoreIsRefusedWhileACopyRuns(t *testing.T) { t.Fatal("after the copy a restore must be allowed") } } + +// Review 2026-10-23 night. N2: a stray clears when a later removal of that name works (it used to block every restore +// until a restart). N3: the start-up check never removes a copy THIS process runs. N4: a second copy into the same +// destination waits for the first instead of removing its container. RED-PROOF: with the stray delete on a successful +// retry removed → StrayClears fails; with the `running` skip removed → OwnCopyKept fails; with the per-destination lock +// removed → SameDestinationWaits fails — each seen failing 2026-10-23 night. +func TestStrayCopy_AStrayClearsWhenALaterRemovalWorks(t *testing.T) { + root, src, dst := appDirs(t) + fail := true + strayCopySeams(t, root, func(context.Context, []string) ([]byte, int, error) { return nil, 0, nil }, + func(args []string) ([]byte, error) { + if fail { + return []byte("Error response from daemon: cannot remove"), errors.New("exit 1") + } + return nil, nil + }) + _ = rsyncMirror(src, dst) + if _, blocked := (&Manager{}).Tier2CopyBlocksRestore(); !blocked { + t.Fatal("fixture: an unremovable leftover must refuse restores") + } + fail = false + if !tier2RetryOnce(context.Background()) { + t.Fatal("the retry must report nothing left once the removal works") + } + if _, blocked := (&Manager{}).Tier2CopyBlocksRestore(); blocked { + t.Fatal("after the stray is removed, restores must be allowed again — without a controller restart") + } +} + +func TestStrayCopy_TheStartUpCheckKeepsThisProcessesOwnCopy(t *testing.T) { + _, life := strayCopySeams(t, t.TempDir()+"/", nil, func(args []string) ([]byte, error) { + if args[0] == "ps" { + return []byte("felhom-tier2-copy-mine-00000001\nfelhom-tier2-copy-old-00000002\n"), nil + } + return nil, nil + }) + tier2MarkRunning("felhom-tier2-copy-mine-00000001", true) + if err := clearLeftoverTier2CopiesOnce(context.Background()); err != nil { + t.Fatal(err) + } + got := life.all() + if strings.Contains(got, "rm -f felhom-tier2-copy-mine-00000001") || !strings.Contains(got, "rm -f felhom-tier2-copy-old-00000002") { + t.Fatalf("the check must remove only the leftover, never this process's running copy:\n%s", got) + } +} + +func TestStrayCopy_ASecondCopyOfTheSameDestinationWaits(t *testing.T) { + root, src, dst := appDirs(t) + var mu sync.Mutex + order := []string{} + release := make(chan struct{}) + first := true + runs, _ := strayCopySeams(t, root, func(context.Context, []string) ([]byte, int, error) { + mu.Lock() + me := first + first = false + order = append(order, "start") + mu.Unlock() + if me { + <-release + } + mu.Lock() + order = append(order, "end") + mu.Unlock() + return nil, 0, nil + }, func(args []string) ([]byte, error) { + mu.Lock() + order = append(order, strings.Join(args, " ")) + mu.Unlock() + return nil, nil + }) + d1, d2 := make(chan error), make(chan error) + go func() { d1 <- rsyncMirror(src, dst) }() + for len(strings.Split(runs.all(), "\n")) < 1 || runs.all() == "" { + time.Sleep(5 * time.Millisecond) + } + go func() { d2 <- rsyncMirror(src, dst) }() + time.Sleep(100 * time.Millisecond) + mu.Lock() + during := strings.Join(order, "|") + mu.Unlock() + if strings.Count(during, "rm -f") != 1 { + t.Fatalf("while the first copy runs, the second must not touch its container: %s", during) + } + close(release) + if err := <-d1; err != nil { + t.Fatal(err) + } + if err := <-d2; err != nil { + t.Fatal(err) + } +}