Files
felhom.eu/documentation/audits/CAMPAIGN-8-backup-restore-2026-07-27.md
T

613 lines
40 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# 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:3008:30)``[19:3023: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**~~**FIXED, controller v0.179.0 (2026-07-28), both causes, replayed live** | ~~HIGH~~ | DEFECT — closed |
| ~~**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~~**FIXED, controller v0.179.0 (2026-07-28); hub DB shows 0 spurious emails, real failures still alarm** | ~~MEDIUM~~ | DEFECT — closed |
| **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 | LOWMED | 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: <div class="app-row stack-state-neutral" ...>
```
The detector was demonstrably alive — **11** `deadapp-check` scans ran after the 180 s grace
expired. The chain: quiesce's `compose down` removes the containers → the failed `compose up`
creates none → deployed + zero containers aggregates to `StateStopped` → and
`main.go:1237` **explicitly excludes** `StateStopped` from the down predicate.
That exclusion rests on an invariant the code states outright at `main.go:1213-1216`:
> "I1: … a deployed stack with zero containers aggregates to StateStopped. So **StateStopped means
> 'deployed, deliberately stopped by the user'**."
**I1 is false.** "Deployed with zero containers" is *also* the state of a failed restart. R-97b
itself is correct and its grace expired on time; v0.164.0's state filter sits downstream and
swallows the case unconditionally. Neither change is wrong alone — composed, they leave a hole.
The quiesce loop already *knows* it tried and failed (`quiesce.go:654`); that outcome simply is not
carried into the classification. Third instance this project has shipped of a comment asserting a
guarantee the code stopped providing.
### F-CRIT-2 — a failed backup that looks like a fresh one
Killing the PBS daemon mid-upload left `ns/demo-felhom/ct/9201/2026-07-27T22:08:31Z` containing
only `.tmp_didx` stubs and **no `index.json.blob`** — yet it is listed as a restorable backup, size
**1 byte**, and it is the NEWEST entry. `NewestArchiveTime` (`runner.go:311-326`) filters on
`Content == "backup"` and `VMID` only, with no completeness test, and the due-check treats storage
as ground truth.
Empirically: the controller UI reported the PBS tier's last backup as *"2026-07-28 00:08 (9
perce)"* — the failed upload. After a controller restart (which clears the in-memory breaker, so
the breaker cannot explain the silence), two full poll cycles produced **no due-tier line at all**,
while the last genuinely successful PBS backup was 2.5 h old against a 2 h cadence — **overdue and
not attempted.** On the real 168 h cadence this suppresses the offsite tier for up to **seven
days**, with every surface reporting it fresh and the hub's ~8-day deadline monitor as the only
remaining net. The R-88 breaker does not help: it defers tiers that are *due*, and this tier is not.
**The signal to reject the phantom already exists one subsystem over.** A full verify flagged
exactly this snapshot:
`manifest load error: unable to load blob '.../index.json.blob' - No such file or directory`.
Two discriminators were available and unused: the missing manifest, and the snapshot's
`verification` state (which the agent's own `VerifyLoop` maintains and which A3/F17 showed
propagating to the Proxmox API).
*Narrowing that makes it more actionable, not less serious:* fault 7 showed that an **ENOSPC**
failure leaves nothing behind — the server was alive and cleaned up. The phantom is specific to the
server dying or becoming unreachable mid-write.
### F-A1 — routine contention reported as failure
A restore-test in flight made the agent correctly refuse a backup (`busy=restore-test`, the R-85
Scenario F gate). The controller treats that HTTP 409 as a tier failure: breaker armed, and
`whole_guest_backup_failed` emailed to the operator — on **both** boxes. No 409 special-casing
exists on the start path (`quiesce.go:455-460`). Two comments assert otherwise:
`inflight.go:18-20` ("A caller that cannot acquire DEFERS to its next cadence" — the backup caller
does not) and `quiesce.go:489-491` (which frames the 409 as what *prevents* "a spurious failure").
Frequency is an ARTIFACT; the behaviour is a DEFECT — at real cadences a ~12-minute restore-test
against a daily backup collides roughly once per 420 guest-days, i.e. **every ~4 days on a
100-guest fleet**, forever training R-97a's alarm into noise.
### F-CRIT-1 and F-A1 — FIXED (controller v0.179.0, 2026-07-28)
**F-CRIT-1**, both causes: `restartAll` now returns the stacks that failed, and `classifyRunStates`
lifts the `StateStopped` whitelist for exactly those (`Loop.FailedRestarts()`). I1 is restated
truthfully — `StateStopped` means "deployed with zero containers", which is EITHER a user stop OR a
failed quiesce restart, and only the loop's own knowledge separates them.
**F-A1**: HTTP 409 is contention, not failure — typed `*StatusError` on POST, mapped to
`quiesce.ErrTierBusy` at the adapter. The tier stays DUE and is dropped before anything stops
(`contentionRetryAfter` 15m), and contention outliving the agent's own 120m PBS restore-test ceiling
raises a **BLOCKED** signal at 3h so a wedged gate is never silent.
Replayed live on demo-hp with the hub DB as arbiter: the failed restart alarmed 9 s after grace
expiry with the banner naming `(stopped)`; a deliberate user stop stayed silent through 9 dead-app
scans; a 409 produced **0** operator emails (8 → 8) while a real transport failure produced **1**
(8 → 9). Six red-proofs. Detail: `felhom-controller/REPORT.md`.
**All three of Campaign 8's HIGH/MEDIUM alarm findings are now closed** (F-CRIT-1, F-CRIT-2, F-A1).
### F-CRIT-2 — FIXED (agent v0.106.0, 2026-07-28)
`NewestArchiveTime` now counts only *plausibly complete* entries, via a measured size floor
(`minPlausibleArchiveBytes` = 1 MiB; smallest real backup on the fleet is 612,397,450 B, so 584x
headroom, asserted by a test). Undecidable ⇒ not counted. Size is the only tier-agnostic
discriminator: `verification` and `encrypted` are absent on every local dir archive and on a good
PBS snapshot until verify-new catches up, so gating on either would have rejected 100% of local
backups and caused fleet-wide backup thrash.
Verified by replaying fault 2 against the fixed agent on demo-hp: the phantom was created, rejected,
and announced once; the tier was correctly reported DUE and backed up; and the inverse case showed
no re-backup thrash (with 91 scheduler ticks proving the loop was alive). Detail:
`felhom-agent/REPORT.md`.
**Also settled:** server-side prune does NOT count phantoms toward `keep-last` — a dry-run retained
two real snapshots PLUS the phantom — so the feared retention/data-loss scenario does not occur. It
never removes them either; filed as R-99.
### F-REBOOT — FIXED (agent v0.107.0, 2026-07-28)
A periodic guest-power watchdog (`internal/localapi/guestpower.go`, 60 s) starts a guest that is
`onboot:1`, stopped, unlocked, and has no vzdump in flight. It closes the two narrow gaps that let
`RecoverStaleLockedGuests` miss fault 11: that recovery acts only on a guest holding a **stale vzdump
lock** (fault 11's guest was unlocked) and runs **once at agent startup** (fault 11's guest went down
while the agent was already up).
`onboot` is the deliberate-stop discriminator, and it is not invented here — it is already what the
stale-lock path uses for this decision, it is 0 on scratch/golden guests, and it is what `pve-guests`
itself consults at host boot, so the agent agrees with the platform rather than keeping a second
private definition of "should be running". Retry is bounded (3 attempts, 1m/2m/4m) and then escalates
once; an unbounded silent retry loop would be the over-correction.
Replayed live on demo-hp: a guest stopped out from under the agent came back **unattended in 120 s**,
against the **587 s** the finding's original incident needed a human. The lock-deferral guard fired
live during the replay. Scenario B proven on the same box — an `onboot:0` guest was left stopped
across the whole window.
### F-LEAK — FIXED (agent v0.110.0 + host-install v1.21.0, 2026-07-28) — after TWO refuted attempts
**Three attempts, two refuted by live test.** Recorded in full because both wrong answers looked right
and one of them shipped.
The cause is structural rather than a missing privilege in the role: `FelhomAgentGuest` is granted at
`/pool/felhom`, and **a guest joins that pool only when its restore completes**, so a *failed*
restore-test leaves a guest that exists, is in no pool, and is out of the token's reach entirely.
**Attempt 1 — adopt the stranded guest into the pool, then retry** (agent v0.107.0, shipped). Fired
exactly as designed and PVE refused it: `PUT /pools/felhom -> HTTP 500: permission denied at /vms/990000
(missing privilege ...)`. `PUT /pools/{pool}` **also** requires `VM.Allocate` on the VM being added —
**pool membership cannot bootstrap its own authority.** Removed in v0.108.0.
**Attempt 2 — grant the role per-path at `/vms/990000..990009`** (host-install v1.21.0). It *works*, and
the live A/B proved it: grant removed → `403 (/vms/990000, VM.Allocate)`, guest still present; grant
restored → `200 UPID:...vzdestroy`, guest gone. **But it is durable for exactly one use per slot.** The
post-destroy check showed `/vms/990000` with **0 grants**, and PVE's own source says why: the destroy
path calls `AccessControl::remove_vm_access($vmid)` (`API2/LXC.pm:906`), which deletes every ACL at
`/vms/<vmid>` (`AccessControl.pm:1898`). **The grant is consumed by the operation it authorises** — after
ten teardowns the band is ungranted and the defect returns. A per-VM ACL is the wrong tool; the pool
grant is durable only because it lives on a *pool* path, which `remove_vm_access` does not touch.
**Attempt 3 — route the destroy through the authority that already performs the create** (agent
v0.110.0). `Privileged.DestroyScratchLXC` is the **fourth** root-fenced exception, and it is fenced
harder than the other three, in three places none of which is consumed by use:
| layer | enforcement |
|---|---|
| **sudoers** | `/usr/sbin/pct destroy 99000[0-9] --purge` — sudo matches the vmid **literally** |
| **`DestroyScratchLXC`** | re-checks the band; refuses an unconfigured or inverted band rather than defaulting |
| **`teardownScratch`** | acts only on this journal entry's own scratch provenance |
The API destroy is still tried **first** and stays the normal path; the v1.21.0 band ACLs stay
provisioned so the common case needs no privileged call at all. This is the fallback that makes teardown
deterministic instead of once-per-slot.
**The fence, proven live by asking sudo rather than executing** (executing the negative case against a
live guest is precisely what must not happen):
| command | sudo verdict |
|---|---|
| `pct destroy 990000 / 990005 / 990009 --purge` | **PERMITTED** |
| `pct destroy 9201 --purge` (the live customer guest) | **REFUSED** |
| `pct destroy 9100 / 9999 / 1 --purge` | **REFUSED** |
| `pct destroy 990010 --purge` (one past the band) | **REFUSED** |
| `pct start 990000` / `pct set 990000 -memory 512` | **REFUSED** — the grant is this one op, not this vmid |
Also proven at the API seam, and worth keeping because it establishes the *shape* of the refusal: a
`DELETE` of the non-existent `990010` returned **403**, not "does not exist" — PVE evaluates
**permission before existence**, so these are genuine authorization refusals rather than artifacts.
Granting `VM.Allocate` at `/vms` was rejected throughout: it would authorise destroying every guest on
the box, including a co-tenant's.
### F-OBS — FIXED (controller v0.180.0, 2026-07-28)
`deadapp-check` now emits a summary line at **INFO** every 20th scan (10 min at its 30 s cadence),
carrying scans-since-boot, stacks evaluated, and how many are currently down. The original silence
came from its per-cycle line going through `Scheduler.dbg()`, which is gated on `logging.level==debug`
and so was never *produced* on a default box — meaning "no alarms" was indistinguishable from "the
detector never ran", the exact fallacy this project has a standing rule against. A line per run was
not an option either (2880/day is what made silence attractive), so the cadence is asserted by test in
both directions: it must not flood, and it must stay frequent enough to expose a stalled detector
inside the 180 s alarm grace it feeds.
*(Full write-ups for every finding, with complete evidence, are in `~/campaign8/evidence/phaseB/`.)*
---
## 6b. Follow-up investigation, 2026-07-28 — R-100 (filed, deliberately NOT fixed)
### A restic offsite tier that fails every night never goes stale on the hub
This is **F-CRIT-2's defect class, one layer up and on the other tier** — a *failed* run resetting the
freshness clock — and it was found by asking whether the F-CRIT-2 shape existed anywhere else.
Two halves, each verified in the source rather than inferred:
- **Controller.** `o.LastRun = time.Now()` is set **unconditionally** in
`controller/internal/backup/offbox.go:716`, outside the `runErr` branch. The failure is recorded
faithfully — but in a *different* field: `o.LastStatus = "error"` at :725.
- **Hub.** `isStale()` reads **only** `off.LastRun`
(`hub/internal/monitor/offsite.go:120`, `:127`, `:131`). It never consults `LastStatus`.
So a nightly restic run that fails every night keeps `LastRun` fresh, `isStale` is permanently false,
and the staleness alarm never fires — while no successful offsite backup has occurred at all.
**Scope of the silence, stated precisely.** `LastStatus` *does* reach the hub: it is parsed into the
report struct and **only logged** (`offsite.go:270`). It drives no checker and no notification. The
controller's own guest UI does surface `LastStatus="error"`, so the failure is *visible to someone who
looks*; what is missing is the push — the operator's fleet-wide alarm plane is silent, which is the
plane that matters for an unattended appliance.
**Not fixed**, per this task's investigation-only scope. Filed as **R-100**; the fix direction is to
gate staleness on the last *successful* run rather than the last attempt, which is precisely what
F-CRIT-2's `NewestArchiveTime` fix did for the PBS tier.
---
## 7. What can come off the "never validated" list
**Retired — proven live tonight:**
- **The R-88 breaker arming** — and its full ladder 15m/30m/1h/2h/4h/4h-cap, its per-target
isolation, and its recovery edge.
- **`whole_guest_backup_failed` from a real failure, end-to-end** — controller → hub → operator
email, with correct tier attribution.
- **R-97c operator-only routing** — verified against the hub DB: **zero** customer rows with
`status='sent'`, plus the deliberate `skipped`/`operator_only` row. (The spec's "zero customer
rows" is imprecise: the skip is logged on purpose so it cannot look like a delivery that never
happened.)
- **`whole_guest_backup_recovered`**, at severity `info`, including the R-68 **pairing gate**
firing live: *"customer mail skipped — no unanswered customer down mail (pairing miss)"*.
- **`age_state=absent`** — a genuinely never-backed-up tier fired the window-gate safety valve and
ran outside a closed window.
- **R-97b's suppression half** — with the detector proven alive by 5 scans inside the window.
- **The crash-recovery unquiesce** — by an actual SIGKILL, recovering in 1 second.
- **R-87: the restic tier has a restore round-trip**, byte-verified.
- **R-82 one-quiesce-two-tiers**, and per-tier isolation under a real one-tier-fails case.
- **Single-flight**: backup vs restore-test, and scheduled vs manual trigger.
- **A restore-test whose source vanishes fails loudly and does NOT falsely advance the tier's
proven-restorable timestamp** (fault 18).
- **R-89's write-only box grant** — the box was correctly refused when it tried to delete its own
offsite snapshot (`missing Datastore.Modify|Datastore.Prune`). A compromised box cannot destroy
its own backups.
**Still NOT validated:**
- **R-97b's other half** — an app that genuinely fails to restart does **not** alarm (F-CRIT-1).
This is now a known defect rather than an open question.
- Restic restore into a fresh guest; the `place`/`reconstitute` legs; demo-hp's restic repo.
- The agent's own DR bring-up path (`ModeDRGuestLoss`) — read in code, never executed.
- Backup + restore-test + **GC** three-way concurrency.
- Guest and host reboots mid-backup.
---
## 8. Final fleet state — HEALTHY, nothing left broken
All four compression knobs reverted and verified on both hosts (`local= 0`, `restore_test= 302400`,
`felhom-pbs 604800`); windows restored (demo-felhom `02:30`, demo-hp back to genuine ABSENCE);
every fault injection unwound. Sweep:
```
leaked scratch guests (990000-990009): NONE nft c8 tables: 0/0
ballast files (host+guest, both boxes): 0 clocks synchronized: yes/yes
ep0 .bad chunks: 0 ep0 pbs daemon: active
ep0 rollback copy /srv/pbs-felhom: PRESENT ep0 datastore: 98G 14G 85G 14%
```
demo-felhom 15/15 containers healthy; demo-hp 8/8. In-memory breakers cleared by the revert
restarts. **The answer to Phase-0 question 4 is that it did not come to that.**
One campaign artefact was removed as part of restoring service, not merely tidiness: F2's partial
snapshot. Leaving it would have left demo-felhom's PBS tier silently suppressed for seven days —
F-CRIT-2's live effect.
### Final verification at 04:57:33Z / 06:57 CEST — after EVERY fault, including the two
### post-Phase-D re-injections (faults 18 and 11)
```
[demo-felhom] agent=active guest=running containers=15 unhealthy=0 scratch=0 nft_c8=0 ballast=0 ntp=yes
[demo-hp] agent=active guest=running containers=8 unhealthy=0 scratch=0 nft_c8=0 ballast=0 ntp=yes
[ep0] pbs=active bad_chunks=0 ballast=0 rollback_copy=PRESENT df=14G/98G 14%
```
**One outage the campaign caused, stated plainly:** fault 11 left demo-hp guest 9201 powered off
for **~9m47s** (03:43:13Z → 03:53:00Z) before I noticed and ran `pct start 9201`. That is finding
F-REBOOT, and it is the longest unplanned downtime of the run. Recovery needed no lock clearing and
all 8 containers returned within ~25 s. Everything else was reverted without incident.
Two re-injections were performed AFTER Phase D because clock-bound work (the 03:30 UTC prune and
GC run 2) left time available. Both are declared rather than hidden: fault 18 needed a bounded
restore-test cadence change on demo-hp (reverted, re-verified), and fault 11 needed no config
change at all. The sweep above is the state after all of it.
---
## 9. What could NOT be tested, and why
- **Fault 4 (storage box unreachable during restic)** — four approaches tried; all failed to
interrupt the run. Root cause of the failure to inject is itself informative: restic runs inside
the guest, so its traffic never enters the host's `output` hook (which is exactly why F1/F3
*did* work — PBS/vzdump traffic is host-originated), and guest 9201 is **bridged**, so it does not
traverse the host's `forward` hook either. `bridge`-family rules would not parse on this nft
version, and a guest-side blackhole route did not cover the container's path. **This is the single
most valuable follow-up**, because F-CRIT-2 raises the analogous question for restic: does an
interrupted restic run leave a partial pack that later looks like success?
- **Fault 12 (host reboot mid-backup)** — not run. Deliberate: F9 and F10 already exercised
hard-kill crash safety for both the agent and the controller, and rebooting a remote Proxmox host
with no console access carried recovery risk disproportionate to the marginal information.
- ~~Fault 18~~ — **was run** in the campaign's tail (see the matrix). It required a single, declared
re-injection after Phase D (restore-test cadence on demo-hp only, 84h→600s), which was reverted
and Phase D re-verified immediately afterwards.
- **Fault 13's true THREE-way overlap** (backup + restore-test + GC simultaneously). Legs A and B were each proven, never together.
- **Fault 6** — inconclusive: ext4's 5% root reserve (2.07 GB, confirmed via `tune2fs`) meant the
filesystem was never truly full for a root-run vzdump. Driving a Proxmox host's root filesystem
to genuine zero risks wedging `pmxcfs`; not attempted.
- **Fault 8** — partial: the volume filled was not the one this guest's app-data backup writes to.
Filling the real target would have meant writing ~890 GB to a remote demo box.
- **Booting either restored guest** — refused on purpose. Their `mp8`/`mp9` binds still point at the
SOURCE guest's live data drive and bootstrap credentials (F-OPS); starting one would have mounted
live customer data read-write beside the running guest.
### Two self-inflicted methodology traps, recorded so they are not repeated
1. **A noise filter deleted the evidence.** `grep -viE 'locale|perl|…'` silently dropped every line
naming `pa`**`perl`**`ess-*` containers, producing a convincing false reading that a quiesce had
failed to restart a stack. Caught only by an arithmetic inconsistency (`docker ps -a -q | wc -l`
= 8 vs 5 formatted lines) and the controller's own container count. Filters are now anchored to
the actual warning lines. **This is the spec's own "absence of a signal is not evidence" rule
biting the campaign's instrumentation rather than the system.**
2. **A ~64 KB single-line ceiling through `ssh → pct exec`** silently returned 0 bytes for a
debug-ring fetch at `limit=400`, and the parser swallowed the error — presenting as "this box has
no DEBUG lines". Parser now fails loudly.
3. **`pgrep -cf <pattern>` matches its own shell** when the pattern appears in the `ssh` command
line that `pgrep -f` inspects. `pgrep -cf vzdump` → 1 while
`ps -eo args | grep -c '[/]usr/bin/vzdump'` → 0. This invalidated fault 11's injection outright
and put one unsound line into fault 9's evidence (withdrawn; that finding stands on the
controller's own job state instead). Drive such triggers off the controller's job log, which is
authoritative and cannot self-match.
All three traps share a shape: **the instrument agreed with the hypothesis for the wrong reason.**
Two were caught only because a second, independent source disagreed — a container count, and a
job-state log. Where no second source existed, the campaign reports NOT TESTED rather than a pass.
---