# CAMPAIGN 8 — the backup & restore subsystem **Adversarial, destructive, unattended. 2026-07-27 19:00 → 2026-07-28 ~06:45 CEST.** Nodes exercised: `demo-felhom` (+ guest 9201), `demo-hp` (+ guest 9201), `ep0` (`felhom-hetzner`, datastore `felhom-offsite`), restic subaccounts `u629488-sub1` / `u629488-sub3`. **`peti-felhom` was never touched.** Neither its data, its namespace, nor `u629488-sub2`. Phase 0 established with five documented probes that peti has NO data in `felhom-offsite` at all (see §1), which is what made the operator-approved datastore-fill safe. The 13 GB rollback copy at `/srv/pbs-felhom` on ep0 was never deleted and is present at the end of the run. Evidence: **`DooPlex:~/campaign8/evidence/`** — 103 files, 35 MB, written continuously by 11 collectors throughout. Nothing in this report is reconstructed after the fact. --- ## Headline Nine findings, two of them HIGH severity, both in the same place: **the system's ability to tell you that a backup did not happen.** - **F-CRIT-1** — an app that fails to restart after a quiesce **never alarms, on any channel**. - **F-CRIT-2** — a failed offsite backup leaves a phantom snapshot that **resets the tier's freshness clock**, silently suppressing the next backup for up to 7 days on production cadences. Everything the campaign was asked to prove about the *happy* path proved out, including the first-ever restic restore round-trip (R-87). The mechanisms designed to catch failure — R-88's breaker, R-97a/c's routing, verify, quarantine, crash recovery — all work, and several are better than documented. The gaps are all in the seams *between* those mechanisms. --- ## 1. Phase 0 — questions, answers, and skips Asked in one batch inside the operator's window, before touching anything. | # | Question | Answer received | |---|---|---| | 1 | How may ep0 be taken down? | **Path-blocking + stop the PBS daemon.** No power-cycle. | | 2 | May VM 300 `drill-r50` be destroyed? | **Free to destroy.** | | 3 | Fill the `felhom-offsite` volume? | **Fill to 100%.** | | 4 | End-of-run bar? | **A broken test node is acceptable if precisely reported.** | **Faults skipped for lack of an answer: none.** All four were answered in the window. One question was NOT put to the operator because it was answerable from configuration, and was verified live instead: the restic subaccount mapping. Confirmed from each guest's `settings.json`: demo-felhom = `u629488-sub1`, demo-hp = `u629488-sub3`. `u629488-sub2` appears in neither box's configuration and was never addressed. **The peti-exposure check (done before asking, so question 3 could be answered honestly).** What was tried, per standing rule 2: 1. `find /mnt/pbs-datastore/ns -maxdepth 3 -type d` → only `demo-felhom`, `demo-hp` 2. `ls -la /mnt/pbs-datastore/` → no depth-0 group dirs 3. `ls -d /mnt/pbs-datastore/{vm,ct,host}/*` → no such paths 4. `proxmox-backup-manager user list` → `felhom@pbs`, `root@pam` only 5. `proxmox-backup-manager prune-job list` → jobs for demo-* namespaces only **Incidental security note, reported at the time:** reading `/etc/felhom-agent/agent.json` printed `hub.api_key` in cleartext into the session transcript (the redactor matched `*token*`/`*secret*`/ `*password*` but not the bare `api_key`). No secret was written to disk or to any campaign file; the operator may wish to rotate. All later captures used a stricter redactor. --- ## 2. Compression applied, and the revert | Knob | Real | Campaign | Ratio | |---|---|---|---| | local (vzdump) cadence | 24 h (via the `0`⇒24h default, `config.go:517-520`) | 1800 s | 48× | | PBS offsite cadence | 604800 s (168 h) | 7200 s | 84× | | restore-test cadence | 302400 s (84 h) | 2700 s | 112× | | backup window start W | `02:30` | rolled 17:30 → 21:30 → (14:00 on demo-hp for F16) | — | Feasibility was measured before choosing, not assumed: demo-felhom's local vzdump is 5.7 GB / `00:03:12`, demo-hp's PBS backup 1.5 GB / `00:00:55`. Both fit a 30-minute cadence with margin. **"Widen the backup window" was not possible.** The gate is `[W+2h, W+6h)` and both offsets are compile-time constants (`backupwindow.go:19-21`); only W is settable. The gate is permanently 4 h wide against a ~10.5 h campaign, so the window was **moved** in contiguous steps rather than widened — which had the side benefit of exercising the gate at three different absolute times. **A compression the spec asked for that configuration cannot deliver:** "restic daily → 30m". The three app-data legs are `Daily` scheduler jobs pinned to fixed offsets from the same W (`main.go:595,632,665`). Moving W reschedules them; it cannot make them 30-minutely. Restic was therefore driven by explicit manual triggers, and **no 30-minute restic cadence was ever in force.** **Revert:** all four knobs restored and verified (§8). demo-hp's `backup_window_start` was restored to genuine ABSENCE from its pre-campaign snapshot rather than written as "02:30", because absent is what it was. ### The pre-registered artifact list Declared BEFORE Phase A so findings could be classified honestly: 1. R-88 breaker cap 4 h — chosen against a 24 h cadence. **ARTIFACT** under compression. 2. R-88 ladder base 15 m — chosen to exceed the 5 m poll. **ARTIFACT**. 3. Window-gate valve "cadence + 24 h" — fires at 24.5 h instead of 48 h. **ARTIFACT**. 4. `quiesceAlarmGrace` 180 s — derived from a 120 s deploy budget and Mealie's 60 s start_period, **not** from cadence. **NOT distorted** → a failure here is a genuine DEFECT. *(This one mattered: F-CRIT-1 lives here.)* 5. `local_backup_retention` 3 — turnover in 90 min instead of 3 days. **ARTIFACT**. --- ## 3. Phase A — the happy path at volume | | demo-felhom | demo-hp | |---|---|---| | quiesce cycles run | 16 | 28 | | unquiesces | 16 | 26 (the 2-cycle gap is F9/F10, where crash-recovery restarted the stacks instead) | | archives on the local tier at end | 3 (retention=3) | 3 (retention=3) | | PBS snapshots at end | 4 | 10 | **A1 — the window gate.** Deferrals captured on both boxes, and the bounds visibly recomputed across a live W change with no restart (`[04:30–08:30)` → `[19:30–23:30)` between two polls 5 minutes apart). 5-minute poll cadence confirmed to the second. *Methodology note that changed the evidence:* demo-felhom runs `level: info`, so none of its quiesce DEBUG lines reach `docker logs`. Judging by docker logs alone would have produced a false "demo-felhom never defers". The lines were recovered from the always-DEBUG ring via `/api/debug/logs?level=DEBUG`, which became a continuous collector. **A2 — R-82 one-quiesce-two-tiers.** Proven end-to-end: ``` 17:30:09 backup due on 2 tier(s) — quiescing 1 stack(s): [paperless-ngx] 17:31:25 tier local: ... done — next tier may start (app still quiesced) 17:31:25 tier felhom-pbs: ... started — polling 17:31:35 tier felhom-pbs: ... snapshotted — resuming app early (8B.2) 17:31:35 unquiescing (snapshotted (early resume, last tier)): restarting 1 stack(s) ``` One window, two tiers, sequential, local first — matching the downtime argument in `tiers.go`. **Total app downtime 86 s** even though the PBS upload continued past the resume. The stop set was exact: during demo-felhom's cycle only the 5 protected infra containers remained, with all 10 app containers of the 4 announced stacks gone. **A3 — `verify-new` populates `verify_state`.** All snapshots `state: ok`; the snapshot this campaign created carried its own per-snapshot verify UPID rather than the shared namespace-wide one. *Near-miss worth recording:* `proxmox-backup-manager verify-job list` on ep0 is **empty**, which reads as "nothing verifies these backups". That would have been a false finding — verification is driven by the **agent's** `VerifyLoop` (6 h, `internal/pbs/verify.go:13`), not by a server-side job. The verify cadence was NOT compressed, so this result applies directly to production. **A4 — prune actually prunes.** Named, not inferred: ``` INFO: prune older backups with retention: keep-last=3 INFO: removing backup 'local:backup/vzdump-lxc-9201-2026_07_27-10_24_37.tar.zst' INFO: pruned 1 backup(s) not covered by keep-retention policy ``` The same logs confirm the three temporary `snap_vm-9201-disk-*_vzdump` LVM volumes are torn down after every run — including on failure paths (verified during F7). No snapshot leaked all night. **PBS-side prune** (`03:30`, keep-last 2) is reported in §3.1 with GC run 2. ### 3.1 GC — both runs, with the atime explanation **Run 1 (early, 17:17:31→17:18:11Z, TASK OK):** ``` Removed garbage: 0 B Removed chunks: 0 Pending removals: 4.669 GiB (in 3903 chunks) On-Disk usage: 7.735 GiB (22.45%) Deduplication factor: 4.45 ``` Correct, and **not a finding** — every chunk carried a fresh atime from the 06:29 migration copy and GC only reclaims past a 24 h+5 m cutoff. The load-bearing line is **`Pending removals`**, not `Removed garbage: 0 B`: per standing rule 3, "0 removed" alone cannot distinguish "deferred correctly" from "did nothing". `Pending removals` is the positive observable — GC walked the index, positively identified 3903 unreferenced chunks, and declined to unlink them because they were too young. **Run 2 (04:44:06Z / 06:44 CEST, after the 04:34 UTC boundary, `TASK OK`):** ``` Removed garbage: 0 B Removed chunks: 0 Pending removals: 6.38 GiB (in 5406 chunks) [run 1: 4.669 GiB / 3903] On-Disk usage: 6.697 GiB (17.11%) / 4891 chunks [run 1: 7.735 GiB / 5910] Deduplication factor: 5.84 [run 1: 4.45] ``` The live set SHRANK and pending removals GREW — the 03:30 UTC prune landing between the runs, with GC correctly re-classifying those chunks as unreferenced. **I predicted run 2 would reclaim ≈4.669 GiB. It reclaimed nothing, and the cause is this campaign.** The datastore is mounted `relatime` (`findmnt -no OPTIONS` → `rw,relatime,discard`), so reading a chunk refreshes its atime — and the campaign read essentially every chunk repeatedly overnight (three full verifies for F17, ~14 backups, two GC runs, several restores). Sampled atimes at 04:55:38Z prove it: ``` 188 chunks atime 2026-07-28 04:xx ← GC run 2 itself, touching referenced chunks (phase 1) 155 chunks atime 2026-07-27 07:xx 51 chunks atime 2026-07-27 21:xx ← a verify pass oldest atime in sample: 2026-07-27 07:18:53Z (21h37m — short of the 24h5m cutoff) ``` No chunk was ever 24h5m cold, so `Removed garbage: 0 B` is exactly correct on both runs. **Not a defect** — GC made a deliberate, correct decision both times, and `Pending removals` is the positive observable proving it did the work. But it IS an operational property worth knowing: **on a `relatime` datastore, activity defers reclamation.** "GC ran, so space will come back" is unsafe on a small offsite box that something reads regularly. **Honest limit:** because the campaign's own reads reset the clock, the spec's intended experiment — watching the migration chunks cross the boundary and be collected — **could not be completed inside the campaign window.** First genuine reclamation should follow ~07:23Z on 07-28. Recorded as an incomplete observation, not a pass. --- ## 4. Phase B — the fault matrix | # | Fault | Outcome | Evidence | |---|---|---|---| | 1 | ep0 unreachable while PBS due | **PASS** — breaker armed, event end-to-end, **per-tier isolation proven** (local succeeded while PBS failed in the same window) | `F1-ep0-unreachable.md` | | 2 | ep0 killed mid-vzdump | **PASS** on chunk-store integrity (0 `.bad`, datastore unchanged) — **but produced F-CRIT-2** | `F-CRIT-2-*.md` | | 3 | wg-felhom down | **PASS** — and attempt 1 SELF-HEALED (60 s watchdog). Attempt 2 (endpoint blocked) → **same error string as fault 1** → F-DIAG | `F3-wg-down.md` | | 4 | storage box unreachable during restic | **NOT TESTED** — 4 injection approaches all failed to interrupt the run; reasons documented | `F4-...-NOT-TESTED.md` | | 5 | stale restic lock from a killed run | **PASS** — recovers, does not wedge; every run begins with an unconditional `restic unlock` | `F5-stale-restic-lock.md` | | 6 | fill local disk mid-backup | **INCONCLUSIVE** — backup succeeded on ext4's 5% root reserve (2.07 GB) while `df` read 100% | `F6-fill-local-disk.md` | | 7 | fill the PBS volume to 100% | **PASS** — clean ENOSPC, no corruption, no leaked LVM snapshot, instant recovery | `F7-fill-pbs-volume.md` | | 8 | fill the guest disk during a quiesce | **PARTIAL** — vzdump correctly unaffected; the write-path volume was not the one filled | `F8-fill-guest-disk.md` | | 9 | kill the agent mid-backup | **PASS** — apps restarted in 10 s; agent auto-restarted in 17 s. (One evidence line withdrawn — see the correction note) | `F9-kill-agent-mid-backup.md` | | 10 | kill the controller mid-quiesce | **PASS** — crash recovery in **1 second**; and it corrects the premise (see below) | `F10-kill-controller-mid-quiesce.md` | | 11 | reboot the guest mid-backup | **FINDING (F-REBOOT)** — the backup succeeded but **the guest never came back**; found `stopped` with 0 containers, no self-heal, ~9m47s outage until manual `pct start` | `F11-reboot-guest-mid-backup.md` | | 12 | reboot the host mid-backup | **NOT TESTED** — see §9 | — | | 13 | backup + restore-test + GC concurrently | **PASS on both tested axes** — backup vs restore-test single-flight HOLDS; backup vs GC coexist (both tiers completed during GC run 2). True three-way overlap not tested | `F13-concurrency.md` | | 14 | two quiesce triggers at once | **PASS** — `TryLock` + skip, exactly one cycle ran | `F14-two-triggers.md` | | 15 | clock skew (+6 h) | **PASS** — gate follows wall clock (correct); **breaker is skew-proof** via Go monotonic time | `F15-clock-skew.md` | | 16 | `age_state=absent` (never observed live) | **PASS** — valve fired, cycle ran OUTSIDE a closed window on a genuinely never-backed-up tier | `F16-age-state-absent.md` | | 17 | corrupt a chunk | **PASS on all four legs** — detect → quarantine `.0.bad` → `verify_state: failed` → restore fails cleanly | `F17-corrupt-chunk.md` | | 18 | delete a snapshot mid restore-test | **PASS on detection** — restore-test failed loudly, did NOT advance the proven-restorable timestamp; **and it root-caused F-LEAK** | `F18-delete-snapshot-mid-restore-test.md` | | 19 | R-97b both halves | **part 1 PASS** (suppression, with the detector proven alive); **part 2 FAIL → F-CRIT-1** | `F19-part1-*.md`, `F-CRIT-1-*.md` | **Fault 10 corrects its own premise.** The spec describes the mechanism as "the guaranteed unquiesce via `defer`". `defer` played no part — it does not run on SIGKILL. What saved the stacks was the **crash marker + `Recover()`**, which fired 1 s after the kill and named the job id and stopped-stack count read back from the marker. The correct statement is: *the unquiesce is guaranteed by the marker, not by the defer.* ### The R-88 backoff ladder — fully validated Driven by a deliberately-failing tier: **15m → 30m → 1h → 2h → 4h → 4h (cap holds)**. All six rungs matched `backoffFor()` exactly. Rung 6 is the important one: the breaker clamps rather than continuing to double, so it **never latches open** — the property `breaker.go:22-26` insists on. R-97a's edge-triggering also held: exactly ONE event per failure *run* per tier, not one per retry, and the edge is tracked per-target (a second tier breaking is not masked by a first). --- ## 5. Phase C — restore round-trips | tier | what was restored | result | |---|---|---| | **restic app-data (R-87)** | `bookstack`, snapshot `b2d8936d`, 155.5 MB, 14 s, via the real `POST /backup/offbox/restore` two-step size gate | **PASS — 6/7 files byte-identical by sha256**, including the 160 MB MariaDB volume dump. The 7th (`manifest.json`) differs only in `controller_version` 0.175.0→0.178.0 and `created_at`, i.e. the restore correctly returned the SNAPSHOT's manifest, not the live one | | local vzdump | 5.82 GB archive → fresh CT 9299 (15 GiB extracted @ 210 MiB/s) | **PASS — exact mount_parity** | | PBS offsite | encrypted snapshot 4.36 GB → fresh CT 9297 | **PASS — exact mount_parity** | | corrupted PBS snapshot | deliberately corrupted snapshot → CT 9298 | **PASS — failed cleanly**: exit 255, named the entry AND the chunk, rolled back all three LVs, left no debris | **mount_parity** was exact on both whole-guest tiers: both storage-backed mountpoints returned with identical in-guest path, `backup=1` flag and size (only volume names changed), and `unprivileged: 1` was preserved — a restore that silently dropped that would be a privilege escalation. **R-87 is retired.** The restic tier now has a proven round-trip. What is NOT retired: restore into a fresh *guest* from restic; the `place`/`reconstitute` legs that turn restored bytes back into a running app; and demo-hp's `u629488-sub3` repo. Restoring bytes is not the same as restoring service, and only the bytes were proven. Neither restored guest was booted — deliberately, see F-OPS below. --- ## 6. Findings, ranked | # | Finding | Severity | DEFECT / ARTIFACT | |---|---|---|---| | **F-CRIT-1** | An app that fails to restart after a quiesce **never alarms** | **HIGH** | **DEFECT** (compression-independent) | | ~~**F-CRIT-2**~~ | ~~A failed offsite backup leaves a phantom snapshot that **resets tier freshness**~~ — **FIXED, agent v0.106.0 (2026-07-28), re-tested live by replaying fault 2** | ~~HIGH~~ | DEFECT — closed | | **F-A1** | A restore-test in progress makes a healthy backup report as FAILED, arms the breaker and pages the operator | MEDIUM | **DEFECT** in behaviour / ARTIFACT in frequency | | **F-HUB** | The hub **dropped an event** under concurrent load (`SQLITE_BUSY`), no retry, cause unnamed | MEDIUM | DEFECT (frequency compression-influenced) | | **F-LEAK** | A **failed** restore-test cannot destroy its own scratch guest (403 `VM.Allocate`); leaks are never reclaimed and the 10-slot VMID band shrinks silently | MEDIUM | DEFECT (root-caused by fault 18) | | **F-REBOOT** | A guest rebooted during its backup **does not come back** — shutdown completes, start never happens, no self-heal | MEDIUM | DEFECT | | **F-DIAG** | Four distinct offsite failure causes collapse into two operator-visible strings | LOW–MED | DEFECT | | **F-OBS** | `deadapp-check` leaves NO positive observable on a default (info-level) box | LOW | DEFECT | | **F-OPS** | A manual `pct restore` inherits the source guest's binds (live data drive + another guest's credentials) | LOW | Operational, not code | ### F-CRIT-1 — the failure that has no alarm A production-faithful injection (one unresolvable image tag in an otherwise intact compose) made `paperless-ngx` fail to restart after a quiesce: ``` 20:46:15 [ERROR] [quiesce] restart paperless-ngx: starting stack paperless-ngx: exit code 1 containers: 0 · controller state: 'stopped' · app_start_failed events: 0 · dashboard banner: 0 dashboard renders the dead app as: