From 342a394bff9d95dc1acacc76a94e4383d093b36f Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Wed, 28 Oct 2026 22:24:16 +0100 Subject: [PATCH] =?UTF-8?q?R-1256:=20four=20restore=20edges=20(review=20ro?= =?UTF-8?q?und=202=20HUNT-1=20H4/H5/H6/H8)=20=E2=80=94=20each=20test=20see?= =?UTF-8?q?n=20failing=20first?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit H4: a failed definition write in the off-site restore writes the live definition back before the start; a failed write-back holds the app (restore_mixed). H5: a put-back whose stop fails pours nothing, keeps the copy and holds the app (off-site, local, power-cut); a failed definition write-back keeps the copy (D20); a failed 'volume rm -f' fails that volume (no merge). H6: TryBeginRestoreOp/RestoreBusy: check every operation and record the restore in one step under m.mu; every web handler and the kept loads begin through it; install-time kept load asks about the mirror too. H8: SweepUnusedRestoreCopies every 6 h: removes a copy only with no hold, no marker naming it, no restore running, and older than 14 days. Commit only; rides the next controller release. --- CHANGELOG.md | 30 ++ REUSE.md | 2 + controller/cmd/controller/main.go | 7 + .../cmd/controller/r1256_sweep_wiring_test.go | 13 + controller/internal/api/kept_install.go | 17 +- controller/internal/api/kept_install_test.go | 45 ++- controller/internal/backup/kept_load.go | 31 +- .../internal/backup/offbox_reconstitute.go | 27 +- .../internal/backup/offbox_restore_undo.go | 19 +- controller/internal/backup/opstatus.go | 47 +++ .../backup/r1256_restore_edges_test.go | 358 ++++++++++++++++++ controller/internal/backup/restore.go | 10 +- .../internal/backup/restore_copy_sweep.go | 129 +++++++ .../internal/backup/restore_crash_putback.go | 4 +- controller/internal/web/handlers.go | 20 +- controller/internal/web/kept_copies.go | 5 +- controller/internal/web/kept_handlers.go | 19 +- controller/internal/web/offbox_handlers.go | 25 +- .../internal/web/r1256_begin_restore_test.go | 60 +++ controller/internal/web/restore_wizard.go | 42 +- 20 files changed, 860 insertions(+), 50 deletions(-) create mode 100644 controller/cmd/controller/r1256_sweep_wiring_test.go create mode 100644 controller/internal/backup/r1256_restore_edges_test.go create mode 100644 controller/internal/backup/restore_copy_sweep.go create mode 100644 controller/internal/web/r1256_begin_restore_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 58406c4c..94856479 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,33 @@ +## Unreleased (2026-10-28 night) — four restore edges (felhom.eu R-1256, review round 2 HUNT-1 H4/H5/H6/H8); commit only, rides the next release + +**MinAgent: 0.158.1** (unchanged). Each edge: a test seen failing first, then the fix; live proof on 9202 in the felhom.eu +night report (`audits/night-2026-10-28/`). + +- **H4 — `internal/backup/offbox_reconstitute.go`:** an off-site restore whose definition write (or database-password + write) fails no longer starts the app at once. The writer writes the compose BEFORE the app's settings, so the stack + dir could hold the snapshot's (older) compose: the live definition is written back first, then the app starts + (`restartAtLiveDefinition`); when the write-back fails too, the app is held (`restore_mixed`), never started on the + snapshot's definition. Tests `TestR1256_H4_*`. +- **H5 — a put-back whose stop fails does not go on.** `putBackAfterFailedRestore` (off-site and local unit restore): + a failed stop pours nothing, keeps the copy and holds the app; a failed definition write-back keeps the copy too (D20: + a put-back that fails keeps its copy). `CrashPutBack.PutBackInterruptedRestore` (a restore cut by a power loss): a + failed stop is an error, so the start holds the app (R-1251 H2) instead of pouring under a running app. + `restoreDockerVolumesFrom`: a `docker volume rm -f` that fails (the volume is in use) counts as a failed volume — the + following `volume create` was a no-op and the tar was unpacked ON TOP of the old content (a merge). Tests + `TestR1256_H5_*`. One log line corrected: a failed start after a put-back no longer says the copy stays (it is removed; + the volumes are back). +- **H6 — a restore begins in the same step as the check for every other operation.** New + `backup.TryBeginRestoreOp` / `RestoreBusy` (under `m.mu`, the lock the second-drive mirror's `beginTier2Run` asks + under): a restore op in flight, the backup run, a second-drive copy. Every web restore handler begins through + `Server.beginRestoreOp` (a source test refuses a direct `BeginRestoreOp`); the kept loads (`LoadKeptApp`, + `LoadKeptOffsite`) return `ErrRestoreBusy` with nothing started, and `LoadKeptApp` takes the dated folder's file move + as `prepare`, inside the operation. The install-time „use my kept data" asks about the second-drive copy too + (`RestoreBusy`, was RestoreStatus/IsRunning only). Tests `TestR1256_H6_*` (backup, web, api). +- **H8 — `internal/backup/restore_copy_sweep.go`:** an unused restore copy goes after 14 days. Every 6 hours + (`restore-copy-sweep`) a copy is removed only when the app has no restore hold of any kind, the app-stop marker is + readable and does not name the app, no restore runs, and the copy is older than 14 days. Tests `TestR1256_H8_*` + (and the wiring test). + ## v0.346.1 (2026-10-27) — SECURITY: traefik v3.7.16, the file manager 1.5.8-stable, cloudflared 2026.10.4 — built from v0.346.0 (`b1b9be3`) + one commit (felhom.eu R-1304, R-1305) **MinAgent: 0.158.1** (unchanged). Box programs only; no other change from v0.346.0. diff --git a/REUSE.md b/REUSE.md index 44dce7dc..8efafbb4 100644 --- a/REUSE.md +++ b/REUSE.md @@ -80,8 +80,10 @@ | `restoreOpInFlight` + `hasRecentRestoreResult` | controller/internal/web/restore_wizard.go | `(backup.RestoreOpStatus) bool` / `(st, app, now) bool` | THE "is a restore running / did one just finish" display reads | **TRAP (v0.154.0 shipped this bug): `Manager` has TWO running flags.** `IsRunning()` reads the CONCURRENCY flag, acquired inside the goroutine — and `RestoreOffboxScratch` never acquires it, so it is false for the whole verification restore. Display must read `RestoreStatus().Running` (set synchronously by `BeginRestoreOp`). Read the status ONCE per render or the strip and the suppression can disagree. `hasRecentRestoreResult` is app-bound and window-bounded — a process-wide result must not light another app's „Eredmény" | | `restoreWizardPath` / `deriveWizardStep` / `resolveWizardApp` | controller/internal/web/restore_wizard.go | `(app) string` / `(restoreWizardInput) restoreWizardView` / `([]OffboxAppRow, name) *OffboxAppRow` | R-48 offsite restore wizard: URL builder + the PURE step/unlock derivation + the app-resolution refusals | The step is **never** taken from the request. Precedence is load-bearing: op-running outranks a stale `?full_prep=`, else a commit button reappears mid-restore. Truth table + red-proof: `restore_wizard_test.go`. Adding a form here that posts anywhere new breaks `TestRestoreWizard_NoNewMutationEndpoints` **by design** — R-48 adds no mutation surface | | `restoreOpBlocked` | controller/internal/web/restore_wizard.go | `() (msg string, blocked bool)` | THE refusal gate before starting ANY restore | **Use this, never a bare `IsRunning()`.** It reads BOTH flags: `RestoreStatus().Running` (set synchronously by `BeginRestoreOp`, true for the whole off-box restore) and `IsRunning()` (the concurrency flag, the only one the nightly backup holds). **R-351: all seven handlers read only `IsRunning()`, which the goroutine acquires AFTER the handler returns — a second press started a second run and was told „…elindult".** Returns the Hungarian refusal, which names the running app and a route | **R-360 (v0.226.0): `offboxVerifyCopyDeleteHandler` was the LAST holdout and its doc comment claimed it already did this — the sentence is why nobody looked. `IsRunning()` is FALSE for the whole of a verification restore, so the copy a restore was writing into could be deleted from the UI (observed live 2026-08-21 22:35). No app-name comparison: refusing during ANY restore is stronger and uniform.** +| `Server.beginRestoreOp` → `backup.TryBeginRestoreOp` / `RestoreBusy` (R-1256 H6) | controller/internal/web/restore_wizard.go; controller/internal/backup/opstatus.go | `(op, stack) (msg string, ok bool)` / `(op, stack) (busy, mirrorApp string)` | THE way a restore op begins: the check for every other operation (a restore op, the backup run, a second-drive copy) and the record in ONE step under `m.mu` — the mirror asks under the same lock (`beginTier2Run`) | **Never call `BeginRestoreOp` from a handler** (`TestR1256_H6_NoHandlerBeginsARestoreUnchecked`): `restoreOpBlocked` asked early can be stale by the time the form is read, and a mirror that began in between ran beside the restore. `restoreOpBlocked` stays as the EARLY refusal; the kept loads begin inside `LoadKeptApp` / `LoadKeptOffsite` and return `ErrRestoreBusy` | | `Manager.RestoreFromRecoveryUnitAt` / `RestoreFromRecoveryUnit` + `UnitRestoreResult` (R-353 v0.226.0; R-102 v0.229.0) | controller/internal/backup/restore_unit.go | `(stack, unitDir string) (UnitRestoreResult, error)` / `(stack string) (…)` | THE local recovery-unit restore, and the facts its surface must state | **Returns a RESULT, not just an error** — volumes replayed, DBs replayed, and what the manifest LISTED. The Manifest* counts are load-bearing: zero-replayed has two causes (the backup held no data / the backup listed data that did not come back) and they are opposite news. Pair it with `unitRestoreOutcomeMsg`; do NOT write a new sentence. **A claim about the APP is forbidden on this path** — it has no `SafetyDump` discriminator, unlike the off-site twin (CONTEXT.md ruling, 07-backup-architecture §6.3). `restoreDockerVolumes` now returns `(int, error)`; `restoreDockerVolumesFrom` is unchanged and still the shared implementation. **R-102: `…At` holds the whole body and takes the unit DIRECTORY; the one-argument form is the thin caller naming the primary unit.** THE SOURCE MOVES; THE DESTINATION DOES NOT — `GetAppDrivePath` still resolves where the data lands. The R-47 mutation order, the unit-over-guest secret precedence, the fail-closed data-key gate and the no-unit `RestoreApp` fallback are all pinned and unchanged. The volume leg goes through the R-354 `volumeReplayFrom` seam so the source directory is assertable without Docker | | `Manager.putBackAfterFailedRestore` + `liveVolumeCopy` (R-893 option A, v0.336.0) | controller/internal/backup/offbox_restore_undo.go | `(stack, cause, live, copy, volumesMoved, filesPlaced, restart, holdKey) error` | THE restore undo — off-site (v0.336.0) and, since D22 (unreleased), the LOCAL unit restore (`RestoreFromRecoveryUnitAtWith`, so also the second drive's and a kept load): the live volumes it will replace, measured before the stop (`planLiveVolumeCopy`), copied right after it (`copyLiveVolumes`), poured back on any failure | One copy per restore under `/backups/restore-undo//` (no capture set reads `backups/`); the put-back uses the restore's own `volumeReplayFrom`/`restoreDockerVolumesFrom`, so there is one volume-replay implementation. A put-back that fails sets `keep` and HOLDS (option C) — never start on volumes that are not known to be back. Seams for tests without Docker: `undoVolumeProbeFn`, `undoVolumeTarFn`, `undoVolumeRemoveFn`; operator notice `SetRestorePutBackNotify` (leg `restore-put-back`). Pinned by `r893_putback_test.go` and `r1177_local_putback_test.go` | +| `Manager.SweepUnusedRestoreCopies` (R-1256 H8) | controller/internal/backup/restore_copy_sweep.go | `(now) []string` | THE only remover of a restore copy nothing names any more (`restore-copy-sweep`, every 6 h) | Removes a copy only when ALL hold: older than 14 days, the app has no restore hold of ANY kind, the app-stop marker is readable and does not name the app, no restore op runs. It answers „no" when it cannot answer — a held or waiting copy is support's way back | | `CrashPutBack` + `Manager.persistUndoForCrash` + `AppStopGuard.SetUndo` (D22 / R-1195, v0.338.0) | controller/internal/backup/restore_crash_putback.go | `NewCrashPutBack(stop, writeDef, logger)`; `PutBackInterruptedRestore(stack, undoDir) error` | A restore cut by a power loss is put back at start: the copy (volumes + `definition/` + `undo.json`) is recorded in the app-stop marker once whole; `Recover` pours it back BEFORE the restart | Call `persistUndoForCrash` right after `copyLiveVolumes` in any new restore path. `Recover` runs before the backup manager exists, so the put-back is wired in main.go with `stackMgr.StopStack` and the stack adapter's definition writer. A failed put-back = a FAILED recovery (app not started, marker kept). The household reads `note.restore.interrupted_put_back` (`LoadRestoreRecordAfterRecovery`). Pinned by `TestR1195_*` | | `tier2CaptureSetFull(...) (legs, missing, warns, classified)` + `keptCopyRels` + `dropKeptCopiesUnder` (R-1252, unreleased) | controller/internal/backup/tier2_capture.go, tier2_kept.go | `classified` = the legs come from a VALID backup block | **The second-drive reconcile deletes only under a valid classification**; a rejected or absent block keeps every dest dir; kept copies (D25) are always in the keep set; a mirror deleted by Remove drops its kept records | A new reconcile caller must take `classified` and the kept rels too — never reconcile against the legacy legs. A rejected block is told by `Manager.BackupBlockRejected` (stacks; via the adapter's optional `BackupBlockRejected` method) and signalled once a day (`SetTier2SettingsUnreadableNotify`). Pinned by `r1252_rejected_block_keeps_copies_test.go` | | `holdreport.Reporter` + `settings.RestoreHold.Why` / `WireReason` (D53, unreleased) | controller/internal/holdreport/holdreport.go · controller/internal/settings/settings.go | `New(store, notifier.PushEvent, logger)`; `Tick(now)` from the scheduler | Tells the hub every hold in place (`app_held`), every hold gone (`app_hold_cleared`), each again daily | **One observer of the hold store — never a send inside a hold writer.** A new hold writer needs nothing here. The hold sentence is `RestoreHold.Why()` (one per reason) — never a second copy. Pinned by `internal/holdreport/holdreport_test.go` | diff --git a/controller/cmd/controller/main.go b/controller/cmd/controller/main.go index 5789f771..00b6b526 100644 --- a/controller/cmd/controller/main.go +++ b/controller/cmd/controller/main.go @@ -1400,6 +1400,13 @@ func main() { return nil }) + // R-1256 H8: a restore copy no hold, no pending put-back and no running restore needs goes after 14 days. Every 6 + // hours — a copy outliving its age by hours costs disk, never data. TestR1256_H8_TheSweepIsWiredAtStartup. + sched.Every("restore-copy-sweep", 6*time.Hour, func(ctx context.Context) error { + backupMgr.SweepUnusedRestoreCopies(time.Now()) + return nil + }) + // Tier 2: off-drive copy of each HDD app's recovery unit + userdata (auto-enabled, auto-target). // Runs after the DB dump so it copies a fresh unit. backupMgr.SetTier2Notifier(func(stackName, destLabel string, dur time.Duration, err error) { diff --git a/controller/cmd/controller/r1256_sweep_wiring_test.go b/controller/cmd/controller/r1256_sweep_wiring_test.go new file mode 100644 index 00000000..fe698548 --- /dev/null +++ b/controller/cmd/controller/r1256_sweep_wiring_test.go @@ -0,0 +1,13 @@ +package main + +import "testing" + +// TestR1256_H8_TheSweepIsWiredAtStartup — R-1256 H8: an unused restore copy goes only through +// SweepUnusedRestoreCopies, so main.go must CALL it (the seam-built-but-never-wired class). +// RED-PROOF: delete the `restore-copy-sweep` job — this fails. +func TestR1256_H8_TheSweepIsWiredAtStartup(t *testing.T) { + lines, _, _ := slice4CallLines(t) + if len(lines["SweepUnusedRestoreCopies"]) == 0 { + t.Fatal("SweepUnusedRestoreCopies is never called — an unused restore copy would stay on the drive for ever") + } +} diff --git a/controller/internal/api/kept_install.go b/controller/internal/api/kept_install.go index 90c73030..4ea860ec 100644 --- a/controller/internal/api/kept_install.go +++ b/controller/internal/api/kept_install.go @@ -94,7 +94,9 @@ func (r *Router) keptDataAtInstall(w http.ResponseWriter, req *http.Request, nam writeJSON(w, http.StatusConflict, apiResponse{OK: false, Error: data.UseOff, Data: data}) return true } - if st := r.backupMgr.RestoreStatus(); st.Running || r.backupMgr.IsRunning() { + // R-1256 H6: every operation — a restore, a backup run, a second-drive copy — not only the first two; and the + // load itself begins in the same step as this question (startKeptLoad → ErrRestoreBusy). + if busy, _ := r.backupMgr.RestoreBusy(); busy != "" { writeJSON(w, http.StatusConflict, apiResponse{OK: false, Error: r.msgLang(lang, "api.kept.busy")}) return true } @@ -104,7 +106,11 @@ func (r *Router) keptDataAtInstall(w http.ResponseWriter, req *http.Request, nam } r.logger.Printf("[INFO] [api] Deploy %s: USE MY KEPT DATA — loading from %s (tier %d, %s) under the kept files %v", name, src, cp.c.Tier, cp.c.Time.UTC().Format(time.RFC3339), old) r.dropLeftoverHold(name, "use-kept-data") // R-704: this is a new install of an app that is not installed - r.startKeptLoad(name, hdd, cp.c, lang, nil) + if err := r.startKeptLoad(name, hdd, cp.c, lang, nil); err != nil { + r.logger.Printf("[WARN] [api] Deploy %s: use my kept data REFUSED at its start: %v", name, err) + writeJSON(w, http.StatusConflict, apiResponse{OK: false, Error: r.msgLang(lang, "api.kept.busy")}) + return true + } writeJSON(w, http.StatusAccepted, apiResponse{OK: true, Message: r.msgLang(lang, "kept.load.started", display)}) return true default: @@ -120,7 +126,7 @@ func (r *Router) keptCopyName(lang string, c backup.KeptCopy) string { // startKeptLoad runs the load and, when it succeeded, the app's after_load. then(ok) runs last. The // off-site copy goes through LoadKeptOffsite (download the unit alone, judge it, then the same restore). -func (r *Router) startKeptLoad(name, drive string, c backup.KeptCopy, lang string, then func(ok bool)) { +func (r *Router) startKeptLoad(name, drive string, c backup.KeptCopy, lang string, then func(ok bool)) error { display := name if st, ok := r.stackMgr.GetStack(name); ok && st.Meta.DisplayName != "" { display = st.Meta.DisplayName @@ -128,10 +134,9 @@ func (r *Router) startKeptLoad(name, drive string, c backup.KeptCopy, lang strin okMsg := func(error) string { return r.msgLang(lang, "kept.load.done", display) } failMsg := func(err error) string { return r.msgLang(lang, "kept.load.failed", display, err) } if c.Tier == backup.KeptTierOffsite { - r.backupMgr.LoadKeptOffsite(name, drive, c, nil, okMsg, failMsg, r.keptAfterLoad(name, then)) - return + return r.backupMgr.LoadKeptOffsite(name, drive, c, nil, okMsg, failMsg, r.keptAfterLoad(name, then)) } - r.backupMgr.LoadKeptApp(name, c.UnitDir, okMsg, failMsg, r.keptAfterLoad(name, then)) + return r.backupMgr.LoadKeptApp(name, c.UnitDir, nil, okMsg, failMsg, r.keptAfterLoad(name, then)) } // keptAfterLoad runs the app's after_load when the load succeeded, then then(ok). diff --git a/controller/internal/api/kept_install_test.go b/controller/internal/api/kept_install_test.go index e79168a7..755dd1f7 100644 --- a/controller/internal/api/kept_install_test.go +++ b/controller/internal/api/kept_install_test.go @@ -162,7 +162,10 @@ func TestR691_InstallChoiceNamesTheOffsiteCopy(t *testing.T) { // copy, restic and the unit restore behind their seams — no Docker). // COMPANION RED-PROOF: remove the dropLeftoverHold call from keptDataAtInstall → the hold is still there // after the 202 and the first assertion fails; remove it from deployStack → the AST check fails. -func TestR704_AFreshInstallDropsALeftoverHold(t *testing.T) { +// keptInstallRig is an installable app with old data on its drive and an off-site copy of its unit; done receives +// once per unit restore the load reaches. +func keptInstallRig(t *testing.T) (*Router, *settings.Settings, string, chan struct{}) { + t.Helper() dir := t.TempDir() drive := filepath.Join(dir, "drive") cfg := &config.Config{} @@ -234,6 +237,11 @@ func TestR704_AFreshInstallDropsALeftoverHold(t *testing.T) { return backup.UnitRestoreResult{}, nil }) r := &Router{stackMgr: m, backupMgr: bm, sett: sett, logger: log.New(io.Discard, "", 0)} + return r, sett, drive, done +} + +func TestR704_AFreshInstallDropsALeftoverHold(t *testing.T) { + r, sett, drive, done := keptInstallRig(t) // A leftover update hold from an earlier install (the demo-hp shape): the new install drops it. _ = sett.SetRestoreHold(settings.RestoreHold{Stack: "cloudapp", At: "2026-09-13T19:56:32Z", Reason: settings.HoldReasonUpdateFailed}) @@ -287,3 +295,38 @@ func TestR704_AFreshInstallDropsALeftoverHold(t *testing.T) { t.Fatalf("deployStack must call dropLeftoverHold before DeployStack (drop=%v deploy=%v)", dropAt, deployAt) } } + +// R-1256 H6: the install-time „use my kept data" asks about EVERY operation — a second-drive copy too, not only a +// restore record and the backup run — and the load begins in the same step as the question. +// RED-PROOF: restore the RestoreStatus/IsRunning-only check and LoadKept*'s plain BeginRestoreOp → 202 and the load +// runs beside the copy → FAILS. +func TestR1256_H6_AKeptLoadAtInstallIsRefusedWhileASecondDriveCopyRuns(t *testing.T) { + r, _, drive, done := keptInstallRig(t) + end := backup.MarkTier2CopyForTest("someapp") + w := httptest.NewRecorder() + req := httptest.NewRequest(http.MethodPost, "/api/stacks/cloudapp/deploy?lang=en", nil) + r.keptDataAtInstall(w, req, "cloudapp", drive, "use") + end() + if w.Code != http.StatusConflict { + t.Fatalf("a load during a second-drive copy: code %d, want 409 — body %s", w.Code, w.Body.String()) + } + select { + case <-done: + t.Fatal("the load ran beside the second-drive copy") + case <-time.After(300 * time.Millisecond): + } + if st := r.backupMgr.RestoreStatus(); st.Running { + t.Fatal("a refused load left a restore op recorded") + } + // The copy ended: the same press loads. + w = httptest.NewRecorder() + r.keptDataAtInstall(w, httptest.NewRequest(http.MethodPost, "/api/stacks/cloudapp/deploy?lang=en", nil), "cloudapp", drive, "use") + if w.Code != http.StatusAccepted { + t.Fatalf("after the copy: code %d — body %s", w.Code, w.Body.String()) + } + select { + case <-done: + case <-time.After(10 * time.Second): + t.Fatal("the load never reached the unit restore") + } +} diff --git a/controller/internal/backup/kept_load.go b/controller/internal/backup/kept_load.go index 580e690c..88240cfa 100644 --- a/controller/internal/backup/kept_load.go +++ b/controller/internal/backup/kept_load.go @@ -301,8 +301,12 @@ func (m *Manager) downloadKeptOffsiteUnit(ctx context.Context, app, drive string // LoadKeptOffsite is LoadKeptApp from the off-site copy c: download the unit alone, judge it, then // prepare (nil = nothing; a dated folder's files move back here), then the one unit restore, then // after(ok). A download failure or a refusal never reaches prepare, so the kept files stay as they were. -func (m *Manager) LoadKeptOffsite(app, drive string, c KeptCopy, prepare func() error, okMsg, failMsg func(err error) string, after func(ok bool)) { - m.BeginRestoreOp("restore", app) +// ErrRestoreBusy (nothing started, after not called) when another operation runs (R-1256 H6). +func (m *Manager) LoadKeptOffsite(app, drive string, c KeptCopy, prepare func() error, okMsg, failMsg func(err error) string, after func(ok bool)) error { + if busy, _ := m.TryBeginRestoreOp("restore", app); busy != "" { + m.logger.Printf("[WARN] [backup] kept load %s REFUSED: a %s operation runs (R-1256)", app, busy) + return ErrRestoreBusy + } go func() { start := time.Now() fail := func(err error) { @@ -345,6 +349,7 @@ func (m *Manager) LoadKeptOffsite(app, drive string, c KeptCopy, prepare func() after(true) } }() + return nil } // RemovedUnitOnDrive is the start-fresh hook (stacks.SetKeptUnitFinder): the removed app's OWN unit when @@ -370,11 +375,26 @@ func (m *Manager) PrimaryUnitHome(app, drive string) string { // LoadKeptApp runs the load as a restore operation the backup pages already follow (the poll banner): // Begin → RestoreFromRecoveryUnitAt(app, unitDir) → End, then after(ok) in the same goroutine (the -// after_load command, the kept folder's tidy-up). The caller has checked RestoreStatus/IsRunning. -func (m *Manager) LoadKeptApp(app, unitDir string, okMsg, failMsg func(err error) string, after func(ok bool)) { - m.BeginRestoreOp("restore", app) +// after_load command, the kept folder's tidy-up). prepare (nil = nothing) runs first, inside the operation — a dated +// folder's files move back there. R-1256 H6: the op is begun in the same step as the check for every other operation; +// a refusal returns ErrRestoreBusy with nothing started and nothing moved. +func (m *Manager) LoadKeptApp(app, unitDir string, prepare func() error, okMsg, failMsg func(err error) string, after func(ok bool)) error { + if busy, _ := m.TryBeginRestoreOp("restore", app); busy != "" { + m.logger.Printf("[WARN] [backup] kept load %s REFUSED: a %s operation runs (R-1256)", app, busy) + return ErrRestoreBusy + } go func() { start := time.Now() + if prepare != nil { + if perr := prepare(); perr != nil { + m.logger.Printf("[ERROR] [backup] kept load %s: preparing the kept files FAILED: %v — nothing was loaded", app, perr) + m.EndRestoreOp(false, failMsg(perr)) + if after != nil { + after(false) + } + return + } + } res, err := m.keptUnitRestore()(app, unitDir) if errors.Is(err, ErrRestoreNotStarted) { m.keptLoadNotStarted(app, err, after) @@ -395,6 +415,7 @@ func (m *Manager) LoadKeptApp(app, unitDir string, okMsg, failMsg func(err error after(true) } }() + return nil } // keptLoadNotStarted (R-1270): the kept data is loaded but the app did not start in time. Never „done": the record says diff --git a/controller/internal/backup/offbox_reconstitute.go b/controller/internal/backup/offbox_reconstitute.go index e3286228..979845dd 100644 --- a/controller/internal/backup/offbox_reconstitute.go +++ b/controller/internal/backup/offbox_reconstitute.go @@ -548,6 +548,25 @@ func (m *Manager) holdAppAfterMixedRestore(stack string, replayErr error, live * } } +// restartAtLiveDefinition (R-1256 H4) is the failure branch of the definition write, taken while no data has moved. +// The writer writes the compose before the app's settings, so a failure can leave the snapshot's compose in the +// stack dir: the LIVE definition is written back first, and only then is the app started. When the write-back fails +// too, the app is held stopped (restore_mixed) — a start would run the snapshot's definition over the live data. +// Pinned by TestR1256_H4_*. +func (m *Manager) restartAtLiveDefinition(stack string, live *liveDefinition, cause error, restartStack func() error) { + if live != nil { + if err := m.stackProvider.RecreateStackDefinitionFromUnit(stack, live.dir, live.env); err != nil { + m.logger.Printf("[ERROR] [offbox] %s: the definition write failed (%v) and writing the live definition back failed too: %v — holding the app stopped", stack, cause, err) + m.holdAppAfterMixedRestore(stack, cause, nil) + return + } + m.logger.Printf("[INFO] [offbox] %s: the definition write failed (%v); the live definition is written back before the start", stack, cause) + } + if sErr := restartStack(); sErr != nil { + m.logger.Printf("[WARN] [offbox] %s: restart after a failed definition write also failed: %v", stack, sErr) + } +} + // SetRestoreHoldNotify wires the operator notification for a held app (cmd/controller/main.go). func (m *Manager) SetRestoreHoldNotify(fn func(stack string, replayErr, rollbackErr error)) { m.restoreHoldNotify = fn @@ -1005,16 +1024,12 @@ func (m *Manager) ReconstituteFromOffsite(ctx context.Context, stack string, ack // yet — a failure here restarts the app as it was. if defineFromSnapshot { if err := m.stackProvider.RecreateStackDefinitionFromUnit(stack, scratchCompose, snapEnv); err != nil { - if sErr := restartStack(); sErr != nil { - m.logger.Printf("[WARN] [offbox] %s: restart after a failed definition write also failed: %v", stack, sErr) - } + m.restartAtLiveDefinition(stack, liveDef, err, restartStack) return res, fmt.Errorf("restoring %s: writing the snapshot's definition failed: %w", stack, err) } } else if len(credOverlay) > 0 { if err := m.stackProvider.(secretValueSetter).SetStackSecretValues(stack, credOverlay); err != nil { - if sErr := restartStack(); sErr != nil { - m.logger.Printf("[WARN] [offbox] %s: restart after a failed password write also failed: %v", stack, sErr) - } + m.restartAtLiveDefinition(stack, liveDef, err, restartStack) return res, fmt.Errorf("restoring %s: writing the backup's database password failed: %w", stack, err) } m.logger.Printf("[INFO] [offbox] %s: the backup's database password(s) %v written into the app's settings before the data (R-1106)", stack, credNames(credOverlay)) diff --git a/controller/internal/backup/offbox_restore_undo.go b/controller/internal/backup/offbox_restore_undo.go index 53853cda..de0dc2cc 100644 --- a/controller/internal/backup/offbox_restore_undo.go +++ b/controller/internal/backup/offbox_restore_undo.go @@ -226,8 +226,13 @@ func (m *Manager) putBackAfterFailedRestore(stack string, cause error, live *liv m.holdAppAfterMixedRestore(stack, cause, live) return util.MsgError(holdKey, stack) } + // R-1256 H5: a put-back under an app that could not be stopped could mix the copy with what the app writes. + // Nothing is poured; the copy is kept and the app held (D20: a put-back that fails holds and keeps its copy). if err := m.stackProvider.StopStack(stack); err != nil { - m.logger.Printf("[WARN] [offbox] %s: stopping the app before the put-back failed: %v", stack, err) + c.keepIfAny() + m.logger.Printf("[ERROR] [offbox] %s: stopping the app before the put-back FAILED: %v — nothing is put back; the copy stays at %s; holding the app", stack, err, c.dirOrNone()) + m.holdAppAfterMixedRestore(stack, cause, live) + return util.MsgError(holdKey, stack) } if volumesMoved { if err := m.putBack(stack, c); err != nil { @@ -239,7 +244,8 @@ func (m *Manager) putBackAfterFailedRestore(stack string, cause error, live *liv } if live != nil { if err := m.stackProvider.RecreateStackDefinitionFromUnit(stack, live.dir, live.env); err != nil { - m.logger.Printf("[ERROR] [offbox] %s: writing the live definition back FAILED: %v — holding the app", stack, err) + c.keepIfAny() // R-1256 H5 (D20): a put-back that fails keeps its copy for support + m.logger.Printf("[ERROR] [offbox] %s: writing the live definition back FAILED: %v — the copy stays at %s; holding the app", stack, err, c.dirOrNone()) m.holdAppAfterMixedRestore(stack, cause, live) return util.MsgError(holdKey, stack) } @@ -249,12 +255,19 @@ func (m *Manager) putBackAfterFailedRestore(stack string, cause error, live *liv m.restorePutBackNotify(stack, cause) } if err := restart(); err != nil { - m.logger.Printf("[ERROR] [offbox] %s: start after the put-back failed: %v (the copy stays at %s)", stack, err, c.dirOrNone()) + m.logger.Printf("[ERROR] [offbox] %s: start after the put-back failed: %v (the live volumes and definition are back; the copy %s is removed)", stack, err, c.dirOrNone()) return util.MsgError("err.backup.restore_failed_put_back_not_started", stack) } return putBackMessage(stack, filesPlaced) } +// keepIfAny marks the copy as kept for support (no copy: nothing to keep). +func (c *liveVolumeCopy) keepIfAny() { + if c != nil { + c.keep = true + } +} + func (c *liveVolumeCopy) dirOrNone() string { if c == nil { return "(no volume copy)" diff --git a/controller/internal/backup/opstatus.go b/controller/internal/backup/opstatus.go index adcedb87..da2c9d57 100644 --- a/controller/internal/backup/opstatus.go +++ b/controller/internal/backup/opstatus.go @@ -62,6 +62,53 @@ type RestoreOpStatus struct { func (m *Manager) BeginRestoreOp(op, stack string) { m.mu.Lock() defer m.mu.Unlock() + m.beginRestoreOpLocked(op, stack) +} + +// Why a new restore may not begin now (R-1256 H6). "" = it may. +const ( + RestoreBusyRestore = "restore" // a restore op is in flight (the record the pages follow) + RestoreBusyBackup = "backup" // the single-flight backup/restore run is held (the night run never records an op) + RestoreBusyMirror = "mirror" // a second-drive copy runs, or one a previous process lost may still run +) + +// TryBeginRestoreOp is BeginRestoreOp that refuses — in the SAME step, under m.mu — while another restore op, a +// backup run or a second-drive copy runs. R-1256 H6: the pages asked (RestoreStatus, IsRunning, +// Tier2CopyBlocksRestore) and recorded the op later; a mirror that began in between ran beside the restore. The mirror +// asks under the same m.mu (beginTier2Run), so one of the two always sees the other. Lock order m.mu → tier2Copies, +// as in beginTier2Run. Returns the busy reason ("" = begun) and, for a mirror, its app ("" when unknown). +// Pinned by TestR1256_H6_*. +func (m *Manager) TryBeginRestoreOp(op, stack string) (busy, mirrorApp string) { + m.mu.Lock() + defer m.mu.Unlock() + if busy, app := m.restoreBusyLocked(); busy != "" { + return busy, app + } + m.beginRestoreOpLocked(op, stack) + return "", "" +} + +// RestoreBusy is TryBeginRestoreOp's question alone — for a refusal asked early, before a request is read further. +func (m *Manager) RestoreBusy() (busy, mirrorApp string) { + m.mu.Lock() + defer m.mu.Unlock() + return m.restoreBusyLocked() +} + +func (m *Manager) restoreBusyLocked() (string, string) { + if m.opRunning { + return RestoreBusyRestore, m.opStack + } + if m.running { + return RestoreBusyBackup, "" + } + if app, blocked := m.Tier2CopyBlocksRestore(); blocked { + return RestoreBusyMirror, app + } + return "", "" +} + +func (m *Manager) beginRestoreOpLocked(op, stack string) { m.opRunning = true m.opName = op m.opStack = stack diff --git a/controller/internal/backup/r1256_restore_edges_test.go b/controller/internal/backup/r1256_restore_edges_test.go new file mode 100644 index 00000000..be73874d --- /dev/null +++ b/controller/internal/backup/r1256_restore_edges_test.go @@ -0,0 +1,358 @@ +package backup + +import ( + "context" + "errors" + "io" + "log" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "gitea.dooplex.hu/admin/felhom-controller/internal/settings" +) + +// R-1256 (review round 2, HUNT-1): four restore edges — H4, H5, H6 and H8, each pinned below. +// +// H4: an off-site restore writes the snapshot's definition before any data moves. The writer +// (stackAdapter.RecreateStackDefinitionFromUnit) writes the compose FIRST and the app's settings after, so a +// failure can come back with the snapshot's compose already in the stack dir. The failure branch used to start +// the app at once — on the snapshot's (older) compose, over the live data. Now the live definition is written +// back first; only then is the app started. When the write-back fails too, the app is held, never started. + +// r1256DefFailProvider fails the FIRST definition write (the snapshot's), after recording it — as the real +// writer does when its compose write succeeded and its settings write did not. +type r1256DefFailProvider struct { + *r893Provider + failWrites int // how many writes fail, from the first + failFrom int // when set, every write from this one (1-based) on fails +} + +func (p *r1256DefFailProvider) RecreateStackDefinitionFromUnit(name, composeDir string, env map[string]string) error { + if err := p.r893Provider.RecreateStackDefinitionFromUnit(name, composeDir, env); err != nil { + return err + } + if len(p.defs) <= p.failWrites || (p.failFrom > 0 && len(p.defs) >= p.failFrom) { + return errors.New("app.yaml write failed") + } + return nil +} + +func r1256DefFailFixture(t *testing.T, failWrites int) (*Manager, *r1256DefFailProvider, *int) { + t.Helper() + m, vp, _, notified, _ := r893FixtureA(t, true, 0) + p := &r1256DefFailProvider{r893Provider: vp, failWrites: failWrites} + m.SetStackProvider(p) + return m, p, notified +} + +// RED-PROOF: remove the live write-back from the definition-write failure branch (restartStack alone) → one +// definition write (the snapshot's), then the start → FAILS. +func TestR1256_H4_AFailedDefinitionWriteStartsTheAppAtItsLiveDefinition(t *testing.T) { + m, p, notified := r1256DefFailFixture(t, 1) + _, err := m.ReconstituteFromOffsite(context.Background(), "immich", false) + if err == nil { + t.Fatal("a failed definition write must be surfaced") + } + if len(p.defs) != 2 || !strings.Contains(strings.Join(p.defs[1], " "), "postgres:18-alpine") { + t.Fatalf("definition writes %v — want the snapshot's, then the LIVE one written back", p.defs) + } + if !p.fullStarted { + t.Fatalf("the app must run again at its live definition — calls %v", p.calls) + } + // The write-back comes BEFORE the start. + lastRecreate, lastStart := -1, -1 + for i, c := range p.calls { + switch c { + case "recreate": + lastRecreate = i + case "start": + lastStart = i + } + } + if lastRecreate > lastStart { + t.Fatalf("the app was started before the live definition was written back — calls %v", p.calls) + } + if held, _ := m.RestoreHoldFor("immich"); held { + t.Fatal("the live definition is back: the app must not be held") + } + if *notified != 0 { + t.Errorf("hold notices %d, want 0", *notified) + } +} + +// The write-back fails too: the stack dir may still hold the snapshot's compose, so the app is NOT started; it is +// held (restore_mixed: the definition moved and could not be put back) and the operator is told once. +// RED-PROOF: start the app when the write-back fails → fullStarted → FAILS. +func TestR1256_H4_AFailedWriteBackHoldsTheApp(t *testing.T) { + m, p, notified := r1256DefFailFixture(t, 2) + _, err := m.ReconstituteFromOffsite(context.Background(), "immich", false) + if err == nil { + t.Fatal("a failed definition write must be surfaced") + } + if p.fullStarted { + t.Fatalf("the app was STARTED although its live definition could not be written back — calls %v", p.calls) + } + held, _ := m.RestoreHoldFor("immich") + if !held { + t.Fatal("no hold: every start path would start the app on the snapshot's definition") + } + if k := m.HoldKind("immich"); k != settings.HoldReasonRestoreMixed { + t.Errorf("hold kind %q, want %q", k, settings.HoldReasonRestoreMixed) + } + if *notified != 1 { + t.Errorf("the operator must be told once, got %d", *notified) + } +} + +// ---- H5: a put-back whose stop fails must not go on; `volume rm -f` errors count; a failed put-back keeps its copy. + +// r1256StopFailProvider fails the Nth StopStack (1-based). +type r1256StopFailProvider struct { + *r893Provider + failAt, n int +} + +func (p *r1256StopFailProvider) StopStack(name string) error { + p.n++ + err := p.r893Provider.StopStack(name) + if p.n == p.failAt { + return errors.New("compose down: timeout") + } + return err +} + +// The off-site put-back: the replay fails after the snapshot's volume replaced the live one; the stop before the +// put-back fails. Pouring the copy back under a running app could mix it with what the app writes, so nothing is +// poured, the copy is KEPT, and the app is held. +// RED-PROOF: restore the „(continuing)" WARN in putBackAfterFailedRestore → the copy is poured and the app started +// → FAILS. +func TestR1256_H5_APutBackWhoseStopFailsDoesNotPourAndKeepsTheCopy(t *testing.T) { + m, vp, rig, _, notified, putBack := r893PutBackFixture(t) + p := &r1256StopFailProvider{r893Provider: vp, failAt: 2} // 1 = the restore's stop, 2 = the put-back's + m.SetStackProvider(p) + _, err := m.ReconstituteFromOffsite(context.Background(), "immich", false) + if err == nil { + t.Fatal("a failed restore must be surfaced") + } + if p.n < 2 { + t.Fatalf("the put-back's stop never ran (stops %d) — the fixture did not reach the put-back", p.n) + } + if len(rig.poured) != 0 || len(rig.removed) != 0 { + t.Fatalf("the copy was poured (%v) / volumes removed (%v) after a FAILED stop", rig.poured, rig.removed) + } + if vp.fullStarted { + t.Fatalf("the app was started after a failed put-back — calls %v", vp.calls) + } + if held, _ := m.RestoreHoldFor("immich"); !held { + t.Fatal("a put-back that could not run must hold the app (D20)") + } + if left := undoCopies(t, rig.undoRoot); len(left) == 0 { + t.Fatal("the copy must be KEPT after a failed put-back (D20)") + } + if *notified != 1 || *putBack != 0 { + t.Errorf("hold notices %d (want 1), put-back notices %d (want 0)", *notified, *putBack) + } +} + +// The live definition cannot be written back after the volumes were poured: the app is held and the copy is KEPT +// (D20: a put-back that fails keeps its copy for support). +// RED-PROOF: drop `c.keep = true` from the definition write-back failure branch → the copy is removed → FAILS. +func TestR1256_H5_AFailedDefinitionWriteBackKeepsTheCopy(t *testing.T) { + m, vp, rig, _, _, _ := r893PutBackFixture(t) + // A version change, so a live definition exists to be written back; the second write (the write-back) fails. + if err := os.WriteFile(vp.composePath, []byte(vtCompose("18")), 0o644); err != nil { + t.Fatal(err) + } + vp.livePins = ParseComposeImages(vp.composePath) + p := &r1256DefFailProvider{r893Provider: vp, failWrites: 0} + p.failFrom = 2 + m.SetStackProvider(p) + _, err := m.ReconstituteFromOffsite(context.Background(), "immich", false) + if err == nil { + t.Fatal("a failed restore must be surfaced") + } + if len(p.defs) < 2 { + t.Fatalf("the write-back never ran: writes %v", p.defs) + } + if held, _ := m.RestoreHoldFor("immich"); !held { + t.Fatal("a failed write-back must hold the app") + } + if left := undoCopies(t, rig.undoRoot); len(left) == 0 { + t.Fatal("the copy must be KEPT after a failed put-back (D20)") + } +} + +// The crash put-back (a restore cut by a power loss): the stop before pouring fails → an error (the guard then +// holds the app and keeps the copy, R-1251 H2), nothing poured. +// RED-PROOF: restore the „(continuing)" WARN in PutBackInterruptedRestore → nil error, the copy poured → FAILS. +func TestR1256_H5_ACrashPutBackWhoseStopFailsRefuses(t *testing.T) { + dir := t.TempDir() + undo := filepath.Join(dir, "backups", "restore-undo", "app", "20261028T000000Z") + mustWrite(t, filepath.Join(undo, "undo.json"), `{"stack":"app","copied":["app_data"],"definition":false}`) + mustWrite(t, filepath.Join(undo, "app_data.tar"), "LIVE") + poured := 0 + cp := NewCrashPutBack(func(string) error { return errors.New("compose down: timeout") }, nil, log.New(io.Discard, "", 0)) + cp.volReplay = func(string, string) (int, error) { poured++; return 1, nil } + if err := cp.PutBackInterruptedRestore("app", undo); err == nil { + t.Fatal("a put-back whose stop failed must return an error") + } + if poured != 0 { + t.Fatal("the copy was poured back under an app that could not be stopped") + } + if _, err := os.Stat(filepath.Join(undo, "app_data.tar")); err != nil { + t.Fatal("the copy must stay on disk") + } +} + +// restoreDockerVolumesFrom: a `docker volume rm -f` that fails (the volume is still in use) used to be ignored; the +// `volume create` that follows is a no-op on an existing volume, so the tar was unpacked ON TOP of the old content — +// a merge. Now that volume counts as failed and is not touched. +// RED-PROOF: ignore the rm error again → the create and the tar run for the volume → FAILS. +func TestR1256_H5_AVolumeThatCannotBeRemovedIsNotMergedInto(t *testing.T) { + bin := t.TempDir() + calls := filepath.Join(bin, "calls.log") + stub := "#!/bin/sh\necho \"$@\" >> " + calls + "\n" + + "case \"$*\" in 'compose version --short') echo v2.29.7;; 'volume rm -f app_busy') echo 'volume is in use' >&2; exit 1;; esac\nexit 0\n" + if err := os.WriteFile(filepath.Join(bin, "docker"), []byte(stub), 0o755); err != nil { + t.Fatal(err) + } + t.Setenv("PATH", bin+string(os.PathListSeparator)+os.Getenv("PATH")) + dump := t.TempDir() + for _, n := range []string{"app_busy.tar", "app_free.tar"} { + mustWrite(t, filepath.Join(dump, n), "tar") + } + m := &Manager{logger: log.New(io.Discard, "", 0)} + n, err := m.restoreDockerVolumesFrom("app", dump) + if err == nil || n != 1 { + t.Fatalf("restored %d, err %v — want 1 and an error naming app_busy", n, err) + } + if !strings.Contains(err.Error(), "app_busy") { + t.Errorf("the error must name the volume: %v", err) + } + b, _ := os.ReadFile(calls) + for _, l := range strings.Split(string(b), "\n") { + if (strings.HasPrefix(l, "volume create") || strings.HasPrefix(l, "run ")) && strings.Contains(l, "app_busy") { + t.Fatalf("the volume that could not be removed was written into: %q", l) + } + } +} + +// ---- H6: a second-drive mirror must not start between the page's refusal and the restore's own record. + +// The page asked (nothing ran), then a mirror began, then the restore began: the begin itself refuses, records +// nothing, and the mirror — asked under the same lock — refuses once a restore is recorded. +// RED-PROOF: make TryBeginRestoreOp record the op without asking (the old BeginRestoreOp) → the restore begins beside +// the mirror → FAILS. +func TestR1256_H6_ARestoreCannotBeginBesideAMirrorThatStartedAfterTheCheck(t *testing.T) { + tier2ResetForTest() + defer tier2ResetForTest() + m, _ := newOffboxManager(t) + if busy, _ := m.RestoreBusy(); busy != "" { + t.Fatalf("fixture: nothing runs, got %q", busy) + } + // the window: the page's check passed; now a mirror begins + if !m.beginTier2Run("immich") { + t.Fatal("fixture: the mirror must begin while no restore is recorded") + } + if busy, app := m.TryBeginRestoreOp("restore", "immich"); busy != RestoreBusyMirror || app != "immich" { + t.Fatalf("the restore began beside a running mirror: busy=%q app=%q", busy, app) + } + if m.RestoreStatus().Running { + t.Fatal("a refused begin left a restore op recorded") + } + tier2CopyEnd("immich") + if busy, _ := m.TryBeginRestoreOp("restore", "immich"); busy != "" { + t.Fatalf("with the mirror done the restore must begin, got %q", busy) + } + if m.beginTier2Run("immich") { + t.Fatal("a mirror began while the restore of the same app is recorded") + } + // a second restore is refused while the first runs; the backup run refuses too + if busy, _ := m.TryBeginRestoreOp("restore", "other"); busy != RestoreBusyRestore { + t.Fatalf("a second restore began beside the first: %q", busy) + } + m.EndRestoreOp(true, "ok") + if err := m.AcquireRunningForTest(); err != nil { + t.Fatal(err) + } + if busy, _ := m.TryBeginRestoreOp("restore", "immich"); busy != RestoreBusyBackup { + t.Fatalf("a restore began beside a backup run: %q", busy) + } + m.ReleaseRunningForTest() +} + +// ---- H8: an unused restore copy is cleaned up; a copy a hold or a pending put-back needs is never touched. + +func r1256Copy(t *testing.T, m *Manager, app string, age time.Duration, now time.Time) string { + t.Helper() + dir := filepath.Join(restoreUndoDir(m.namespaceRoot(m.systemDataPath), app), now.Add(-age).UTC().Format(restoreCopyStampLayout)) + mustWrite(t, filepath.Join(dir, app+"_data.tar"), "LIVE") + return dir +} + +func r1256Exists(p string) bool { _, err := os.Stat(p); return err == nil } + +// RED-PROOF: drop the hold check (or the marker check) from SweepUnusedRestoreCopies → the held / named copy is removed +// → FAILS; drop the age check → the young copy is removed → FAILS. +func TestR1256_H8_OnlyAnUnusedOldCopyIsRemoved(t *testing.T) { + m, sett := newOffboxManager(t) + now := time.Now() + old := 20 * 24 * time.Hour + unused := r1256Copy(t, m, "unused", old, now) + young := r1256Copy(t, m, "young", 24*time.Hour, now) + held := r1256Copy(t, m, "held", old, now) + waiting := r1256Copy(t, m, "waiting", old, now) + named := r1256Copy(t, m, "named", old, now) + if err := sett.SetRestoreHold(settings.RestoreHold{Stack: "held", At: now.Format(time.RFC3339), Reason: settings.HoldReasonRestoreMixed}); err != nil { + t.Fatal(err) + } + if err := sett.SetRestoreHold(settings.RestoreHold{Stack: "waiting", At: now.Format(time.RFC3339), Reason: settings.HoldReasonPutBackPending}); err != nil { + t.Fatal(err) + } + // a restore cut by a power loss: the marker (no longer active after a failed recovery's End) still names the copy + if err := m.appStop.Begin("unit-restore:named", ReasonUnitRestore, []string{"named"}); err != nil { + t.Fatal(err) + } + if err := m.appStop.SetUndo("named", named); err != nil { + t.Fatal(err) + } + + got := m.SweepUnusedRestoreCopies(now) + if len(got) != 1 || got[0] != unused || r1256Exists(unused) { + t.Fatalf("removed %v — want exactly the unused old copy %s", got, unused) + } + for _, keep := range []string{young, held, waiting, named} { + if !r1256Exists(keep) { + t.Errorf("a needed copy was removed: %s", keep) + } + } + if r1256Exists(filepath.Dir(unused)) { + t.Error("the emptied per-app folder must go too") + } +} + +// While a restore runs nothing is removed; a marker that cannot be read stops the sweep. +// RED-PROOF: drop the RestoreBusy check → the old copy goes during a restore → FAILS. +func TestR1256_H8_NothingIsRemovedDuringARestoreOrWithAnUnreadableMarker(t *testing.T) { + m, _ := newOffboxManager(t) + now := time.Now() + c := r1256Copy(t, m, "app", 20*24*time.Hour, now) + m.BeginRestoreOp("restore", "other") + if got := m.SweepUnusedRestoreCopies(now); len(got) != 0 || !r1256Exists(c) { + t.Fatalf("removed %v during a restore", got) + } + m.EndRestoreOp(true, "ok") + mustWrite(t, m.appStop.path, "{not json") + if got := m.SweepUnusedRestoreCopies(now); len(got) != 0 || !r1256Exists(c) { + t.Fatalf("removed %v with an unreadable marker", got) + } + if err := os.Remove(m.appStop.path); err != nil { + t.Fatal(err) + } + if got := m.SweepUnusedRestoreCopies(now); len(got) != 1 { + t.Fatalf("control: with nothing in the way the old copy goes, removed %v", got) + } +} diff --git a/controller/internal/backup/restore.go b/controller/internal/backup/restore.go index 1cff33c0..02e29936 100644 --- a/controller/internal/backup/restore.go +++ b/controller/internal/backup/restore.go @@ -224,8 +224,14 @@ func (m *Manager) restoreDockerVolumesFrom(stackName, dumpDir string) (int, erro m.logger.Printf("[INFO] [backup] Restoring Docker volume %s for %s", volName, stackName) - // Remove existing volume (ignore errors — may not exist) - dockerexec.Command("docker", "volume", "rm", "-f", volName).Run() + // Remove the existing volume. `rm -f` of a missing volume succeeds, so an error means the volume EXISTS and + // could not be removed (still in use). R-1256 H5: it used to be ignored — the `volume create` below is a no-op + // on an existing volume, and the tar was unpacked ON TOP of the old content (a merge). That volume fails now. + if out, err := dockerexec.Command("docker", "volume", "rm", "-f", volName).CombinedOutput(); err != nil { + m.logger.Printf("[ERROR] [backup] Failed to remove volume %s before the restore: %s — %v (not written into)", volName, strings.TrimSpace(string(out)), err) + failed = append(failed, volName) + continue + } // Create fresh volume — WITH the labels compose gives its own volumes (R-658, v0.268.0). A bare // `volume create` made a volume the update's undo (until v0.267.0) could not find, and one diff --git a/controller/internal/backup/restore_copy_sweep.go b/controller/internal/backup/restore_copy_sweep.go new file mode 100644 index 00000000..af056974 --- /dev/null +++ b/controller/internal/backup/restore_copy_sweep.go @@ -0,0 +1,129 @@ +package backup + +import ( + "encoding/json" + "os" + "path/filepath" + "sort" + "time" +) + +// R-1256 H8 (review round 2, HUNT-1): a restore copy (/backups/restore-undo//) that nothing +// will ever use again used to stay on the drive for good. A copy is KEPT on purpose in three states — a put-back that +// failed (the app is held, D20), a put-back waiting for its drive (the putback_pending hold, R-1251) and a restore cut +// by a power loss (the app-stop marker names it, D22) — and for 30 minutes after a restore while the box watches for a +// stable start (R-1270). Every one of those is still needed. A copy outside all of them — the app runs again, or was +// removed, and nothing names the copy — is disk the household cannot see or use. +// +// The rule (safest reading, decided in the 2026-10-28 night run; operator may change the age): a copy is removed only +// when ALL of these hold, and the sweep removes NOTHING when it cannot answer one of them: +// - it is older than restoreCopyUnusedAge (its folder's stamp; the folder's time when the stamp does not parse); +// - the app has no restore hold of any kind (held apps keep every copy — support decides); +// - the app-stop marker does not name the app (a pending put-back), and the marker is readable; +// - no restore op is in flight on the box (a new restore's copy and the stable-start watcher are left alone). +// +// Run every 6 hours from main.go (TestR1256_H8_TheSweepIsWiredAtStartup). Pinned by TestR1256_H8_*. + +// restoreCopyUnusedAge is how long an unused copy stays for support after its restore. +const restoreCopyUnusedAge = 14 * 24 * time.Hour + +// restoreCopyStampLayout is copyLiveVolumes' folder name. +const restoreCopyStampLayout = "20060102T150405Z" + +// SweepUnusedRestoreCopies removes the restore copies no hold, no pending put-back and no running restore needs, and +// older than restoreCopyUnusedAge. Returns the folders removed. +func (m *Manager) SweepUnusedRestoreCopies(now time.Time) []string { + if busy, _ := m.RestoreBusy(); busy == RestoreBusyRestore { + m.logger.Printf("[INFO] [backup] restore-copy sweep skipped: a restore runs") + return nil + } + named, ok := m.appStopNamedApps() + if !ok { + m.logger.Printf("[WARN] [backup] restore-copy sweep skipped: the app-stop marker cannot be read — a copy it names must not go") + return nil + } + var removed []string + for _, nsRoot := range m.primaryUnitRoots() { + base := filepath.Join(nsRoot, "backups", "restore-undo") + apps, err := os.ReadDir(base) + if err != nil { + continue + } + for _, a := range apps { + if !a.IsDir() { + continue + } + app := a.Name() + if named[app] { + continue + } + if m.settings == nil { + return removed // no hold store: a held app cannot be told apart + } + if _, held := m.settings.GetRestoreHold(app); held { + continue + } + appDir := filepath.Join(base, app) + copies, err := os.ReadDir(appDir) + if err != nil { + continue + } + sort.Slice(copies, func(i, j int) bool { return copies[i].Name() < copies[j].Name() }) + for _, c := range copies { + if !c.IsDir() { + continue + } + dir := filepath.Join(appDir, c.Name()) + at, err := time.Parse(restoreCopyStampLayout, c.Name()) + if err != nil { + fi, sErr := os.Stat(dir) + if sErr != nil { + continue + } + at = fi.ModTime() + } + if now.Sub(at) < restoreCopyUnusedAge { + continue + } + if err := os.RemoveAll(dir); err != nil { + m.logger.Printf("[WARN] [backup] %s: the unused restore copy %s could not be removed: %v", app, dir, err) + continue + } + m.logger.Printf("[INFO] [backup] %s: the unused restore copy %s (from %s) is removed — no hold, no pending put-back, older than %s (R-1256)", + app, dir, at.UTC().Format(time.RFC3339), restoreCopyUnusedAge) + removed = append(removed, dir) + } + _ = os.Remove(appDir) // the per-app folder, when it is now empty + } + } + return removed +} + +// appStopNamedApps reads the app-stop marker without side effects: the apps of an ACTIVE marker and every app its Undo +// names. ok=false when the marker exists and cannot be read — the caller then touches nothing. +func (m *Manager) appStopNamedApps() (map[string]bool, bool) { + named := map[string]bool{} + if m.appStop == nil || m.appStop.path == "" { + return named, true + } + data, err := os.ReadFile(m.appStop.path) + if os.IsNotExist(err) { + return named, true + } + if err != nil { + return nil, false + } + var mk AppStopMarker + if err := json.Unmarshal(data, &mk); err != nil { + return nil, false + } + for app := range mk.Undo { + named[app] = true + } + if mk.Active { + for _, app := range mk.Stacks { + named[app] = true + } + } + return named, true +} diff --git a/controller/internal/backup/restore_crash_putback.go b/controller/internal/backup/restore_crash_putback.go index 3a83ba12..aab9a730 100644 --- a/controller/internal/backup/restore_crash_putback.go +++ b/controller/internal/backup/restore_crash_putback.go @@ -195,9 +195,11 @@ func (p *CrashPutBack) PutBackInterruptedRestore(stack, undoDir string) error { if j.Stack != stack { return fmt.Errorf("the restore copy at %s belongs to %q, not %q", undoDir, j.Stack, stack) } + // R-1256 H5: never pour the copy back under an app that could not be stopped — a refusal here is a failed + // put-back: the guard holds the app and keeps the copy (R-1251 H2). if p.stop != nil { if err := p.stop(stack); err != nil { - p.logger.Printf("[WARN] [appstop] %s: stopping before the put-back failed: %v (continuing)", stack, err) + return fmt.Errorf("stopping %s before the put-back: %w", stack, err) } } mgr := &Manager{logger: p.logger, volumeReplayFrom: p.volReplay, undoVolumeRemoveFn: p.volRemove} diff --git a/controller/internal/web/handlers.go b/controller/internal/web/handlers.go index 1861c24b..234212f7 100644 --- a/controller/internal/web/handlers.go +++ b/controller/internal/web/handlers.go @@ -1894,7 +1894,10 @@ func (s *Server) backupRestoreHandler(w http.ResponseWriter, r *http.Request) { } s.logger.Printf("[WARN] [web] Restore requested (async): stack=%s, snapshot=%s from %s", stackName, snapshotID, r.RemoteAddr) - s.backupMgr.BeginRestoreOp("restore", stackName) + if msg, ok := s.beginRestoreOp("restore", stackName); !ok { + http.Redirect(w, r, "/backups/restore?flash_error="+url.QueryEscape(msg), http.StatusFound) + return + } go func() { start := time.Now() // Phase 2b: restore from the app's recovery unit (recovers secrets from the guest, fail-closed @@ -2236,7 +2239,10 @@ func (s *Server) backupTier2RestoreHandler(w http.ResponseWriter, r *http.Reques } s.logger.Printf("[WARN] [web] Tier-2 file restore requested (async): stack=%s from %s", stackName, r.RemoteAddr) - s.backupMgr.BeginRestoreOp("tier2-restore", stackName) + if msg, ok := s.beginRestoreOp("tier2-restore", stackName); !ok { + http.Redirect(w, r, "/backups/apps?flash_error="+url.QueryEscape(msg), http.StatusFound) + return + } go func() { n, err := s.backupMgr.RestoreTier2Files(stackName) if err != nil { @@ -2311,7 +2317,10 @@ func (s *Server) backupTier2UnitRestoreHandler(w http.ResponseWriter, r *http.Re // (R-538), which is what left such an app with no way back from the second drive. if s.backupMgr.HasDriveFileLegs(stackName) { s.logger.Printf("[WARN] [web] Tier-2 WHOLE restore requested (async, files + database): stack=%s from %s", stackName, r.RemoteAddr) - s.backupMgr.BeginRestoreOp("tier2-whole-restore", stackName) + if msg, ok := s.beginRestoreOp("tier2-whole-restore", stackName); !ok { + http.Redirect(w, r, "/backups/apps?flash_error="+url.QueryEscape(msg), http.StatusFound) + return + } go func() { start := time.Now() res, err := s.backupMgr.RestoreTier2Whole(stackName) @@ -2346,7 +2355,10 @@ func (s *Server) backupTier2UnitRestoreHandler(w http.ResponseWriter, r *http.Re } s.logger.Printf("[WARN] [web] Tier-2 UNIT restore requested (async, OVERWRITES live data): stack=%s from %s", stackName, r.RemoteAddr) - s.backupMgr.BeginRestoreOp("tier2-unit-restore", stackName) + if msg, ok := s.beginRestoreOp("tier2-unit-restore", stackName); !ok { + http.Redirect(w, r, "/backups/apps?flash_error="+url.QueryEscape(msg), http.StatusFound) + return + } go func() { start := time.Now() res, err := s.backupMgr.RestoreTier2Unit(stackName) diff --git a/controller/internal/web/kept_copies.go b/controller/internal/web/kept_copies.go index 0e2ade28..34d05c0b 100644 --- a/controller/internal/web/kept_copies.go +++ b/controller/internal/web/kept_copies.go @@ -106,7 +106,10 @@ func (s *Server) keptUnitRestoreHandler(w http.ResponseWriter, r *http.Request) return } s.logger.Printf("[WARN] [web] Restore of %s from a set-aside unit requested (async): %s from %s", k.Source, k.Path, r.RemoteAddr) - s.backupMgr.BeginRestoreOp("restore", k.Source) + if msg, ok := s.beginRestoreOp("restore", k.Source); !ok { + http.Redirect(w, r, "/backups/restore?flash_error="+url.QueryEscape(msg), http.StatusFound) + return + } go func() { app, res, err := s.backupMgr.RestoreSetAsideUnit(id) if err != nil { diff --git a/controller/internal/web/kept_handlers.go b/controller/internal/web/kept_handlers.go index f1bebd1e..3f26d0f5 100644 --- a/controller/internal/web/kept_handlers.go +++ b/controller/internal/web/kept_handlers.go @@ -217,16 +217,23 @@ func (s *Server) keptLoadHandler(w http.ResponseWriter, r *http.Request) { _, err := s.stackMgr.RestoreKeptFiles(it) return err } + // R-1256 H6: the load begins in the same step as the check for every other operation; a refusal moves nothing + // (the dated folder's files move back inside the operation, as prepare). + var lErr error if c.Tier == backup.KeptTierOffsite { s.logger.Printf("[INFO] [web] kept LOAD %s: %s from the off-site snapshot %s (from %s)", it.App, it.Path, c.SnapshotID, r.RemoteAddr) - s.backupMgr.LoadKeptOffsite(app, it.Drive, c, moveBack, okMsg, failMsg, after) + lErr = s.backupMgr.LoadKeptOffsite(app, it.Drive, c, moveBack, okMsg, failMsg, after) } else { - if err := moveBack(); err != nil { - s.keptRedirect(w, r, "flash_error", s.errText(r, err)) - return - } s.logger.Printf("[INFO] [web] kept LOAD %s: %s from %s (from %s)", it.App, it.Path, c.UnitDir, r.RemoteAddr) - s.backupMgr.LoadKeptApp(app, c.UnitDir, okMsg, failMsg, after) + lErr = s.backupMgr.LoadKeptApp(app, c.UnitDir, moveBack, okMsg, failMsg, after) + } + if lErr != nil { + msg, _ := s.restoreOpBlocked() + if msg == "" { // the other operation ended in the meantime + msg, _ = s.restoreBusyMessage(backup.RestoreBusyRestore, "") + } + s.keptRedirect(w, r, "flash_error", msg) + return } http.Redirect(w, r, "/backups/restore?"+flashQuery("flash", "flash.restore.started"), http.StatusFound) } diff --git a/controller/internal/web/offbox_handlers.go b/controller/internal/web/offbox_handlers.go index ab4bd4bf..2a366947 100644 --- a/controller/internal/web/offbox_handlers.go +++ b/controller/internal/web/offbox_handlers.go @@ -450,7 +450,10 @@ func (s *Server) offboxRestoreHandler(w http.ResponseWriter, r *http.Request) { return } full := mode == "full" - s.backupMgr.BeginRestoreOp("offbox-restore", app) + if msg, ok := s.beginRestoreOp("offbox-restore", app); !ok { + offboxRedirectTo(w, r, restoreWizardPath(app), msg, true) + return + } go func() { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) defer cancel() @@ -538,7 +541,10 @@ func (s *Server) offboxReconstituteHandler(w http.ResponseWriter, r *http.Reques // data"; this one answers "yes, into a different place than the backup recorded". One checkbox // carrying both would be the two-decisions-one-button shape R-48 removed from this surface. ackPlacement := r.FormValue("ack_placement") == "1" - s.backupMgr.BeginRestoreOp("offbox-reconstitute", app) + if msg, ok := s.beginRestoreOp("offbox-reconstitute", app); !ok { + offboxRedirectTo(w, r, restoreWizardPath(app), msg, true) + return + } go func() { ctx, cancel := context.WithTimeout(context.Background(), 60*time.Minute) defer cancel() @@ -678,7 +684,10 @@ func (s *Server) offboxPlaceHandler(w http.ResponseWriter, r *http.Request) { offboxRedirectTo(w, r, restoreWizardPath(app), offsiteScratchIncompleteKey, true) return } - s.backupMgr.BeginRestoreOp("offbox-place", app) + if msg, ok := s.beginRestoreOp("offbox-place", app); !ok { + offboxRedirectTo(w, r, restoreWizardPath(app), msg, true) + return + } go func() { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) defer cancel() @@ -711,7 +720,10 @@ func (s *Server) sharesRestoreHandler(w http.ResponseWriter, r *http.Request) { offboxRedirectTo(w, r, "/backups/restore", msg, true) return } - s.backupMgr.BeginRestoreOp("shares-restore", backup.SharesDisplayName) + if msg, ok := s.beginRestoreOp("shares-restore", backup.SharesDisplayName); !ok { + offboxRedirectTo(w, r, "/backups/restore", msg, true) + return + } go func() { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) defer cancel() @@ -737,7 +749,10 @@ func (s *Server) sharesPlaceHandler(w http.ResponseWriter, r *http.Request) { offboxRedirectTo(w, r, "/backups/restore", msg, true) return } - s.backupMgr.BeginRestoreOp("shares-place", backup.SharesDisplayName) + if msg, ok := s.beginRestoreOp("shares-place", backup.SharesDisplayName); !ok { + offboxRedirectTo(w, r, "/backups/restore", msg, true) + return + } go func() { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) defer cancel() diff --git a/controller/internal/web/r1256_begin_restore_test.go b/controller/internal/web/r1256_begin_restore_test.go new file mode 100644 index 00000000..663de54c --- /dev/null +++ b/controller/internal/web/r1256_begin_restore_test.go @@ -0,0 +1,60 @@ +package web + +import ( + "go/ast" + "go/parser" + "go/token" + "os" + "path/filepath" + "strings" + "testing" + + "gitea.dooplex.hu/admin/felhom-controller/internal/backup" +) + +// R-1256 H6: every restore handler records its op through beginRestoreOp, which asks about every other operation in +// the same step (backup.TryBeginRestoreOp). A handler that calls BeginRestoreOp directly re-opens the window between +// the early refusal and the record. RED-PROOF: put one `s.backupMgr.BeginRestoreOp(...)` back → FAILS, naming the file. +func TestR1256_H6_NoHandlerBeginsARestoreUnchecked(t *testing.T) { + files, _ := filepath.Glob("*.go") + for _, f := range files { + if strings.HasSuffix(f, "_test.go") { + continue + } + src, err := os.ReadFile(f) + if err != nil { + t.Fatal(err) + } + fs := token.NewFileSet() + af, err := parser.ParseFile(fs, f, src, 0) + if err != nil { + t.Fatal(err) + } + ast.Inspect(af, func(n ast.Node) bool { + if sel, ok := n.(*ast.SelectorExpr); ok && sel.Sel.Name == "BeginRestoreOp" { + t.Errorf("%s: a direct BeginRestoreOp — begin through s.beginRestoreOp (R-1256 H6)", fs.Position(sel.Pos())) + } + return true + }) + } +} + +// The handler's begin refuses with the household's sentence when a second-drive copy began after the early check. +func TestR1256_H6_TheBeginRefusesWithTheCopySentence(t *testing.T) { + s, _, _ := newOffboxWebServer(t) + if _, blocked := s.restoreOpBlocked(); blocked { + t.Fatal("fixture: nothing runs") + } + done := backup.MarkTier2CopyForTest("immich") + msg, ok := s.beginRestoreOp("offbox-reconstitute", "immich") + done() + if ok || !strings.Contains(msg, "második meghajtóra") { + t.Fatalf("the begin must refuse with the copy named; ok=%v %q", ok, msg) + } + if s.backupMgr.RestoreStatus().Running { + t.Fatal("a refused begin recorded a restore") + } + if _, ok := s.beginRestoreOp("offbox-reconstitute", "immich"); !ok { + t.Fatal("after the copy the begin must work") + } +} diff --git a/controller/internal/web/restore_wizard.go b/controller/internal/web/restore_wizard.go index f66297e8..3f9866ae 100644 --- a/controller/internal/web/restore_wizard.go +++ b/controller/internal/web/restore_wizard.go @@ -209,28 +209,50 @@ func (s *Server) restoreOpBlocked() (string, bool) { if s.backupMgr == nil { return "", false } - if st := s.backupMgr.RestoreStatus(); restoreOpInFlight(st) { + busy, app := s.backupMgr.RestoreBusy() + return s.restoreBusyMessage(busy, app) +} + +// beginRestoreOp records a restore op in the SAME step as the check for every other operation (R-1256 H6): the early +// restoreOpBlocked answer can be stale by the time a handler has read its form, and a second-drive copy that began in +// between ran beside the restore. A refusal returns the same sentence as restoreOpBlocked; the caller redirects with it +// and starts nothing. Every restore handler begins through here — TestR1256_H6_NoHandlerBeginsARestoreUnchecked. +func (s *Server) beginRestoreOp(op, stack string) (string, bool) { + busy, app := s.backupMgr.TryBeginRestoreOp(op, stack) + if busy == "" { + return "", true + } + if s.logger != nil { + s.logger.Printf("[WARN] [restore] %s of %s refused at its start — a %s operation runs (R-1256)", op, stack, busy) + } + msg, _ := s.restoreBusyMessage(busy, app) + return msg, false +} + +// restoreBusyMessage is the household's sentence for a RestoreBusy reason ("" = not busy). +func (s *Server) restoreBusyMessage(busy, app string) (string, bool) { + switch busy { + case "": + return "", false + case backup.RestoreBusyRestore: subject := "Egy visszaállítási művelet" - if st.Stack != "" { - subject = "Egy visszaállítási művelet (" + st.Stack + ")" + if app != "" { + subject = "Egy visszaállítási művelet (" + app + ")" } return subject + " már fut, ezért most nem indítható újabb. Az állapotát ezen az oldalon " + "követheted; amint befejeződik, újra indíthatsz visszaállítást.", true - } - if s.backupMgr.IsRunning() { + case backup.RestoreBusyBackup: return "Egy mentési művelet már fut, ezért most nem indítható visszaállítás. Az állapotát " + "ezen az oldalon követheted; amint befejeződik, újra indíthatsz visszaállítást.", true - } - // The stray-copy fix: a second-drive copy (rsync --delete) runs now, or one a previous controller process lost may - // still run — a restore beside it could lose the files it brings back (R-1180's other direction). - if app, blocked := s.backupMgr.Tier2CopyBlocksRestore(); blocked { + default: + // The stray-copy fix: a second-drive copy (rsync --delete) runs now, or one a previous controller process lost + // may still run — a restore beside it could lose the files it brings back (R-1180's other direction). if s.logger != nil { s.logger.Printf("[WARN] [restore] restore refused — a second-drive copy is running or may still run (app=%q)", app) } return "Éppen fut a második meghajtóra készülő mentési másolat, ezért most nem indítható visszaállítás. " + "Néhány perc múlva próbáld újra.", true } - return "", false } // backupsRestoreWizardHandler renders GET /backups/restore/app?name= — the single entry the