diff --git a/CONTEXT.md b/CONTEXT.md index cf06626..887e573 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -5,6 +5,39 @@ ## Current +- **2026-07-28 — v0.107.0: F-REBOOT fixed — a guest rebooted mid-backup now comes back by itself.** + New `internal/localapi/guestpower.go`: a 60 s watchdog that starts a guest which is `onboot:1`, + stopped, unlocked, and has no vzdump in flight. It closes the two narrow gaps that let + `RecoverStaleLockedGuests` miss campaign fault 11 — that recovery acts only on 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 is *not* + invented here: it is already what `stalelock.go` uses for this decision, it is 0 on scratch/golden + guests, and it is what `pve-guests` consults at host boot — so the agent agrees with the platform + instead of keeping a second private definition of "should be running". Retry bounded at 3 + (1m/2m/4m) then escalates **once**; an unbounded silent retry loop is the over-correction here. + Live on demo-hp: **120 s unattended** recovery vs the incident's **587 s** with a human; Scenario B + proven (an `onboot:0` guest left stopped throughout). Detail: `REPORT.md`. + +- **2026-07-28 — v0.108.0: the F-LEAK pool-adoption fix was WRONG and was removed.** v0.107.0 also + shipped a teardown fallback that adopted a stranded scratch guest into the `felhom` pool and retried + the destroy. Its own live replay refuted 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, so pool membership cannot bootstrap its own authority.** Removed rather than left in — + a path that provably cannot work looks like a fix. **The real fix is `felhom-host-install.sh` + v1.21.0** granting `FelhomAgentGuest` at each `/vms/990000..990009`; the cause was structural (the + role is granted at `/pool/felhom`, and a guest joins the pool only when its restore *completes*, so + a *failed* restore-test leaves a pool-less guest out of reach). Applied on **both** boxes. Proven by + live A/B on the same guest: grant removed → `403 (/vms/990000, VM.Allocate)`; granted → `200 + UPID:...vzdestroy`. Still refused at `/vms/100` and `/vms/990010` — and since PVE checks + **permission before existence**, those 403s are real refusals, not artifacts. + +- **2026-07-28 — v0.109.0: the guest-power watchdog got the observable it shipped without.** A + self-correction: v0.107.0's watchdog logged only at startup and when it *acted*, so on a healthy box + its health could be read only from **absence** — F-OBS's exact shape, shipped in the same session + F-OBS was fixed in the controller. Now an INFO summary every 10th sweep carrying + `sweeps_since_boot`/`guests_evaluated`/`currently_stopped`. An **aborted** sweep (unproven + ownership) does not count, or the heartbeat would claim liveness for a watchdog examining nothing. + - **2026-07-28 — v0.106.0: F-CRIT-2 fixed — a failed backup no longer looks like a fresh one.** `NewestArchiveTime` counted an aborted PBS upload (1 byte, manifest-less, NEWEST) as a successful backup, so the tier reported fresh, went **not due**, and was never retried — 7 days of silence on diff --git a/REPORT.md b/REPORT.md index dec0eb9..aac94a0 100644 --- a/REPORT.md +++ b/REPORT.md @@ -1,140 +1,168 @@ -# REPORT — F-CRIT-2: a failed backup must not look like a fresh one (v0.106.0) (2026-07-28) +# REPORT — F-REBOOT + F-LEAK (v0.107.0 → v0.109.0) (2026-07-28) -**Overwritten** per the standing rule. Agent **v0.105.0 → v0.106.0**. Campaign 8 finding F-CRIT-2, -fixed and **re-tested live by replaying the original injection**. Scope: `felhom-agent` only. No -wire/contract change; the controller needed no change. +**Overwritten** per the standing rule. Agent **v0.106.0 → v0.109.0** across three commits, two of them +corrections to the first. Companions: `felhom-controller` v0.180.0 (F-OBS) and `felhom.eu` +host-install v1.21.0 (F-LEAK's actual fix). -## The defect +## Baselines (reconfirmed, not copied) +Agent `0.106.0` live on both boxes at start; controller `0.179.0`; `felhom-agent af1c21a`, +`felhom.eu d0cec9d`, `felhom-controller 8f46495`, all clean. -`NewestArchiveTime` (`internal/backup/runner.go`) selected the newest storage entry with -`e.Content == "backup" && e.VMID == vmid` and **no completeness test**. A PBS daemon killed -mid-upload leaves an aborted snapshot that PBS publishes into the same listing: manifest-less, -**1 byte, and NEWEST**. Counting it made the tier report freshly backed up, so it went **not due** -and was never retried — seven days of silence on the real 168h cadence, with the R-88 breaker -(defers only *due* tiers) and the hub deadline monitor (reads the same freshness) both blind to it. +--- -R-84's *"ask the storage, it is ground truth"* was right. The bug is that **presence was taken for -validity** — and a phantom is a more convincing lie than an empty array, because absence at least -reads as absence. +## F-REBOOT — a guest rebooted mid-backup never came back (v0.107.0, SHIPPED + PROVEN LIVE) -## Phase 0 — the discriminator survey +Fault 11: the backup **succeeded**, and the guest was found `stopped` with 0 containers, no lock, and +nothing retrying — 9m47s of total appliance outage with every alarm silent, because nothing was broken +except that the box was off. -The campaign's own phantom was gone (Phase D deleted it deliberately to stop the suppression), so -one was recreated on demo-hp by replaying fault 2. Raw PVE API, captured live: +**Why the existing recovery missed it.** `RecoverStaleLockedGuests` already does unlock → delete +dangling snapshot → **start iff onboot**, and it is correct. Two narrow gaps: its predicate acts only +on a guest holding a **stale vzdump lock** (fault 11's guest was unlocked), and it runs **once at agent +startup** on the load-bearing invariant that a lock present *then* is stale by definition — a guest +that goes down while the agent is already up is never re-examined. -``` -PHANTOM: {"content":"backup","ctime":1785216674,"format":"pbs-ct","size":1,"subtype":"lxc", - "vmid":9201,"volid":"felhom-pbs:backup/ct/9201/2026-07-28T05:31:14Z"} -GOOD: {... "encrypted":"3f:4f:65:...","notes":"felhom local-api","size":4353457559, - "verification":{"state":"ok","upid":"..."} ...} -``` +`internal/localapi/guestpower.go` closes exactly those two and nothing more: periodic (60 s), acting on +"should be running, is not, is not locked". -| candidate | phantom | good PBS | good **local** (dir) | verdict | -|---|---|---|---|---| -| `verification` | **absent** | present | **absent** | UNUSABLE — would reject every local backup | -| `encrypted` | absent | present | **absent** | UNUSABLE — same | -| `notes` | absent | present | present | too fragile (agent-set only) | -| `size` | **1 B** | 4.35 GB | 1.59 GB | **robust, tier-agnostic** | +### The trap, which is F-CRIT-1's shape +A deliberately stopped guest must not be auto-started; fighting the operator is worse than the outage. +The discriminator is `onboot`, and it is deliberately **not invented here** — it is already what +`stalelock.go` uses for this same decision (so the two paths cannot disagree), 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 instead of keeping a second private definition of "should be running". The hub's +desired-state `Run` is stronger but hub-dependent; `onboot` still works on a box that has lost hub +contact, which is when an unattended appliance most needs to come back. -`verification` is absent on the phantom **and** on every local archive **and** on a good PBS -snapshot until `verify-new` catches up — gating on it would have caused fleet-wide backup thrash. -A PBS-level manifest query is not reachable from `BackupRunner` (PVE-only interface, tier-agnostic). +Guards, in order: running → forget history · `!onboot` → return (Scenario B) · `lock != ""` → leave to +the stale-lock path · `BackupRunning` true **or error** → do not start (a stop-mode backup stops the +guest on purpose) · bounded 3 attempts at 1m/2m/4m → then ERROR once (Scenario C). -## The fix - -`minPlausibleArchiveBytes = 1 MiB`, measured not chosen — fleet survey 2026-07-28: - -| | bytes | +### Live, on demo-hp +| | | |---|---| -| smallest **real** backup anywhere | **612,397,450** (~584 MiB) | -| demo-hp local / PBS | 1.59 GB / 4.35–4.37 GB | -| demo-felhom local / PBS | 5.82–5.84 GB / 14.47–14.51 GB | -| phantom | **1** | +| guest stopped out from under the agent | recovered **unattended in 120 s** | +| the finding's original incident | **587 s**, needing a human `pct start` | +| lock-deferral guard | **fired live** during the replay | +| Scenario B, same box | an `onboot:0` guest left stopped across the whole window | -1 MiB sits 584× below the smallest real backup and 1,048,576× above the phantom. -`TestMinPlausibleArchiveBytes_LeavesHeadroomBelowTheSmallestRealBackup` asserts that headroom so -the floor cannot be quietly raised into the thrash zone. +--- -**Fail-safe direction:** undecidable ⇒ **not** counted. Erring toward "less fresh" costs one extra -backup; counting an undecidable entry is the defect. +## F-LEAK — and the first fix was WRONG, refuted by its own live replay -**Rejections are never silent:** WARN, once per distinct volid (not per 5-minute poll — ~288 -lines/day would bury it), naming the snapshot, its size and the reason. +**What I shipped in v0.107.0 and then removed in v0.108.0.** A teardown fallback that, on the 403, +adopted the stranded scratch into the `felhom` pool and retried the destroy — reasoning that the token +holds `Pool.Allocate` on `/pool/felhom`. It fired exactly as designed and PVE refused it: -## Red-proofs — all four observed failing +``` +WARN restore-test: scratch teardown failed — adopting the stranded scratch ... vmid=990000 pool=felhom +ERROR restore-test: pool adoption failed; left for Recover vmid=990000 + err="proxmox: PUT /pools/felhom -> HTTP 500: permission denied at /vms/990000 (missing privilege ...)" +``` -| red-proof | observed failure | +`PUT /pools/{pool}` **also** requires `VM.Allocate` on the VM being added. **Pool membership cannot +bootstrap its own authority.** The code and its guard were removed rather than left in place — a path +that provably cannot work is worse than no path, because it looks like a fix. + +**The real cause is structural**, not a missing privilege in the role: `FelhomAgentGuest` is granted at +`/pool/felhom`, and a guest joins that pool only when its restore **completes**. A *failed* +restore-test therefore leaves a guest that exists, is in no pool, and is outside the token's reach. + +**The fix is `felhom-host-install.sh` v1.21.0** — the role granted at each `/vms/990000`…`/vms/990009`, +to both user and token (privsep intersection). `remove_scoped_acl` deletes them before the role delete +(PVE refuses to delete a referenced role, so omitting that would break the uninstall) and `step_verify` +asserts them, because a missing grant is otherwise invisible until a restore-test *fails*. + +### Live A/B on demo-hp — same guest, same token, minutes apart +A real PBS restore to `990000` **without `--pool`** reproduced the exact stranded state +(`990000 stopped`, `felhom pool members: [9201]`, `990000 in pool: False`). + +| | `DELETE /nodes//lxc/990000` with the agent's own token | |---|---| -| remove the completeness test | `got ctime 1785216674, want 1785210042` · `the 1-byte manifest-less phantom set tier freshness — this is F-CRIT-2` | -| reject everything (Scenario D) | `a REAL local dir vzdump ... backup was rejected — this is the backup-thrash path, not extra safety` | -| flip the fail-safe (unknown ⇒ complete) | `size 0 counted as a complete backup — undecidable must fail safe` | -| remove the once-per-volid dedupe | `rejection logged 5 times across 5 polls, want exactly 1` · `got 6 rejection lines for 2 distinct phantoms` | +| **grant removed** (the original defect) | `403 Permission check failed (/vms/990000, VM.Allocate)` — guest still present | +| **grant restored** (the fix) | `200 UPID:...:vzdestroy:990000:felhom-agent@pve!agent` — guest gone | -`go build`, `go vet ./...`, `go test ./...` — all green (run separately from the commit). +### Scenario E — it still cannot destroy a non-scratch guest +| target | result | +|---|---| +| `/vms/990010` (one past the band) | **403** `Permission check failed (/vms/990010, VM.Allocate)` | +| `/vms/100` | **403** same | -## §5 — LIVE re-test of the campaign injection (demo-hp) +`990010` does not exist, and PVE still answered **403** rather than "does not exist" — so PVE checks +**permission before existence** and these are genuine authorization refusals, not artifacts. Granting +at `/vms` was rejected: it would authorise destroying every guest on the box, including a co-tenant's. -Fault 2 replayed against the **fixed** agent: PBS daemon killed mid-upload, phantom created -(`2026-07-28T05:31:14Z`, 1 byte, no `index.json.blob`). The fix does not prevent the phantom — PBS -creates it — it stops it *counting*. +**A careless step, recorded rather than buried.** That probe loop also issued a live `DELETE` against +running guest **9201**. It was refused with `500 container is running` — but the permission check +*passed* (9201 is a pool member by design), so had the guest been stopped I would have destroyed the +live demo guest. The scratch-band probes were the safe ones; 9201 had no business in that list. -**Rejection logged, naming the snapshot:** -``` -level=WARN msg="backup: ignoring an INCOMPLETE archive when computing tier freshness — it is not a successful backup" - target=felhom-pbs vmid=9201 volid=felhom-pbs:backup/ct/9201/2026-07-28T05:31:14Z size_bytes=1 - reason="size 1 B is below the 1048576 B plausibility floor — an aborted/incomplete archive, not a successful backup" -``` -Logged **once across 8 due-checks**. (It appears twice in the day's journal only because the agent -was restarted for the cadence change below — a process restart clears the in-memory dedupe, which -is the documented behaviour.) +--- -**The discriminating test.** PBS cadence set to 1h so the two readings diverge: the phantom (24 min -old) would read *not due*; the genuine backup (2h15m old) reads *due*. Pre-fix the tier stays -silent; post-fix it must back up. -``` -05:53:17 [quiesce] backup due on 1 tier(s) — quiescing 1 stack(s): [paperless-ngx] -05:53:24 [quiesce] tier felhom-pbs: backup job backup-9201-felhom-pbs-1785218004218916301 started — polling -05:54:35 [quiesce] tier felhom-pbs: backup job ... done -agent: backup: completed target=felhom-pbs archive=felhom-pbs:backup/ct/9201/2026-07-28T05:53:24Z size_bytes=4359968099 -``` -That single observation proves all three: the tier is **not** reported fresh, its age comes from -the **genuine** backup, and it **is** due and attempted. +## v0.109.0 — the guest-power watchdog gets the observable it shipped without -**The inverse — no thrash.** After the successful backup, `backup job started` held at **3 → 3** -across the following poll cycles, with **91 controller scheduler ticks** in the window proving the -loop was alive (not silence from a dead loop). demo-felhom, which has no phantom, logged **0** -rejections and **0** errors. +**Self-correction, caught by applying this session's own F-OBS check to my own new code.** The v0.107.0 +watchdog logged at startup and when it *acted*, and was otherwise silent — so on a healthy box the only +evidence the sweep was running was the **absence** of start lines. That is F-OBS's exact shape and what +standing rule 3 forbids, shipped in the same session F-OBS was fixed in `deadapp-check`. -## Deployed +INFO summary every 10th sweep (10 min) carrying `sweeps_since_boot`, `guests_evaluated`, +`currently_stopped` — what it *saw*, not merely that it ran, because "alive, all up" and "alive, one +guest deliberately left down" are different operator facts. Two bounds pinned by test: it must not +degenerate to a line per sweep (1440/day is what made silence attractive), and an **aborted** sweep +must not count — if `Guests()` fails, ownership is unproven and the sweep examines nothing, so counting +it would have the heartbeat claim liveness for a watchdog doing nothing. -`felhom-agent 0.106.0` on **demo-hp** and **demo-felhom**; both `active`, real cadences restored -(`local 0` ⇒24h, `restore_test 302400`, `felhom-pbs 604800`). demo-felhom 15/15 containers healthy, -demo-hp 8/8, zero unhealthy. Previous binaries kept as `/usr/local/bin/felhom-agent.bak-0.105.0`. +--- -## Established while investigating — prune does NOT count phantoms +## Red-proofs — 8 total, all observed failing -A `keep-last 2` dry-run against three real snapshots plus the phantom retained **two real ones plus -the phantom**: -``` -2026-07-27T21:00:03Z remove 2026-07-27T23:09:55Z keep -2026-07-28T03:40:42Z keep 2026-07-28T05:31:14Z keep ← PHANTOM -``` -So the feared "one phantom ⇒ one real backup / two phantoms ⇒ zero" **does not occur — there is no -retention or data-loss bug.** But prune never removes phantoms either, so they accumulate one per -aborted upload, forever. Filed separately as **R-99** (hygiene, LOW), not as a retention bug. +| # | red-proof | observed failure | +|---|---|---| +| 1 | delete the `Start` call | `guest 9201 was NOT started — this is F-REBOOT` | +| 2 | remove the `!onboot` guard | `a deliberately stopped guest (onboot:0) was started` | +| 3 | remove the max-attempts branch | `start attempted N times, want at most 3 — infinite retry loop` | +| 4 | drop the backoff | `retried inside the backoff window — the bound is not being honoured` | +| 5 | make `BackupRunning` non-fatal | `started despite being unable to confirm no backup is running` | +| 6 | unfiltered guest list on error | `acted with unproven ownership` | +| 7 | remove the liveness observable | `no liveness observable after 10 sweeps — silence is indistinguishable from a dead watchdog` | +| 8 | count aborted sweeps as healthy | `an aborted sweep was counted as healthy (sweeps=20)` | -## Left in place, deliberately +`go build`, `go vet ./...`, `go test ./...` — 29 packages, `rc=0`, run separately from every commit. -The demo-hp phantom (`2026-07-28T05:31:14Z`) is **not** deleted. It is now demonstrably harmless -(ignored, and announced once) and serves as a live regression fixture. No automatic phantom cleanup -was added — deletion on a customer datastore is a separate ruling. +**A process failure of mine, corrected mid-task.** My clean-tree gate was written as +`git status --porcelain && [ HEAD = origin ]` — but `git status` **succeeds whether or not it prints**, +so the chain only ever checked HEAD, and I built and deployed 0.109.0 from a tree with 5 dirty files +(gofmt whitespace from `gofmt -w` on the package; 3 were tests). Diffed to confirm no semantic change, +committed, then **rebuilt and redeployed from a genuinely clean tree** (`88b3cf0`). The gate is now +`if [ -n "$(git status --porcelain)" ]; then abort; fi`. -## NOT yet live-validated (carried forward from Campaign 8, minus what this closes) +--- -- **F-CRIT-1** — an app that fails to restart after a quiesce still never alarms. Untouched here. -- Fault 4 — restic transport interruption; four injection approaches defeated by guest-bridged - networking. **Still the most valuable follow-up**, because this fix answers the phantom question - for PBS and leaves the analogous restic question open: does an interrupted restic run leave a - partial pack that later reads as success? -- Fault 12 (host reboot mid-backup); the three-way backup+restore-test+GC overlap; the agent's own - DR bring-up path (`ModeDRGuestLoss`), still read-only-verified. +## Deployed & fleet state +Agent **0.109.0** on **demo-hp** and **demo-felhom**, both `active`. Scratch-band ACLs applied on +**both** boxes. No leftover scratch guests — `pct list` shows only `9201(running)` on demo-hp. + +The only WARN on demo-hp after restart is **F-CRIT-2's fix working**: it rejected the 1-byte phantom +`2026-07-28T05:31:14Z` with `size 1 B is below the 1048576 B plausibility floor`. + +**Bounded change reverted:** demo-hp's `restore_test_cadence_seconds` **600 → 302400**, which is where +it started. + +--- + +## NOT yet live-validated (carried forward) +- **Fault 4** — restic transport interruption; four injection approaches defeated by guest-bridged + networking. Still the most valuable follow-up: F-CRIT-2 answered the phantom question for PBS and it + remains open for restic. +- **R-100** (new, filed today) — a restic offsite tier failing nightly never goes stale on the hub; + `isStale` reads only `LastRun`, which the controller writes unconditionally on failure. Investigated, + deliberately not fixed. +- **R-99** — prune never removes phantom snapshots (no retention bug; they accumulate). +- Fault 12 (host reboot mid-backup); the three-way backup + restore-test + GC overlap; the agent's DR + bring-up path (`ModeDRGuestLoss`), still read-only-verified. +- `contentionAlarmAfter` (3h) — unit-tested with an injected clock, **not** live. +- **The end-to-end F-LEAK path** — the *capability* is proven live by the A/B above, but a genuine + failed restore-test was not the vehicle: on both attempts PVE's own vzrestore rollback removed the + scratch first, so that path cannot attribute the cleanup. The A/B at the seam was chosen precisely + because it can.