R-193: demo-hp offsite restored on the box; escrow correction recorded
gates / gates (push) Successful in 7s

Re-issue through the designed endpoint: fresh password staged 07:11:51, settle-gate
GO, consumed 15s later at 07:12:06, offsite configured at 07:12:09 against the SAME
sub-account (275124) and repo path. Both boxes now escrowed.

CORRECTION to this session's own reading: the escrow did NOT recover by itself.
escrow_state went pending -> escrowed 15s after the apply and I inferred automation;
the operator had run the ceremony. It needed a human on both boxes — demo-hp at
07:16:02, demo-felhom at 07:20:28 (its escrow had been pending since its own rebuild
the day before). A 15-second state change is not evidence of automation, which is the
same class as reading an absent log line as success.

Snapshot continuity is NOT established: both boxes report snapshot_count 0, but the
run-history keys are ABSENT rather than zeroed — a controller that has never run an
offbox backup, not an empty repo. The 04:15 run decides it.
This commit is contained in:
2026-08-04 09:23:08 +02:00
parent 2584dfb938
commit 33f0ab2f33
2 changed files with 8 additions and 8 deletions
+7 -7
View File
@@ -20,13 +20,13 @@ Proven end to end on real hardware.
## What's broken
- **One demo machine has no off-site copy of its app data, and rebuilding it is what took it away.**
`demo-hp` was rebuilt on 3 August; before that its off-site backup was healthy and had run
successfully at 04:16 that morning (15 snapshots). The rebuilt machine came up without it and has
not had it in 108 check-ins since. **The cause is that the off-site password is delivered exactly
once and a rebuilt machine cannot ask for another** — the other demo machine survived the same
rebuild only because it happened to have an unused password waiting for it, and recovered in 76
seconds. Nothing about that difference was designed. *(R-193)*
- **Rebuilding a machine silently takes away its off-site app-data backup.** `demo-hp` was rebuilt on
3 August and came up without one, and stayed that way for a day. **Fixed on 4 August** — re-issued,
the machine picked the new password up in 15 seconds and reattached to the same repository, and you
escrowed the key. **The underlying fault is not fixed:** the off-site password is delivered exactly
once and a rebuilt machine cannot ask for another, so this will happen again on the next rebuild.
The other machine survived the same rebuild only because an unused password happened to be waiting
for it. *(R-193)*
- **The daily email about it tells you the wrong story**, and the automatic repair that exists for
this declines without saying why. The message says the password was never applied; it was, on
23 July, and worked for eleven days. *(R-192)*
+1 -1
View File
@@ -36,7 +36,7 @@ State: `BLOCKED` · `READY` · `WAITING-ON-OPERATOR` · `WATCHING`. Every row ha
| **R-190** | **A storage ACL that demonstrably WORKED in the morning was gone by mid-morning, and nothing recorded its removal.** On demo-felhom, a `vzdump` by `felhom-agent@pve!agent` with `--storage felhom-backup` completed **OK at 04:44:50 CEST 2026-08-03** (task log read in full). From **09:24:56** the same path returned `HTTP 403 … missing privilege Datastore.Allocate at /storage/felhom-backup`, six times through the day, until the grant was re-applied by hand at 18:54. By ~14:50 `pveum acl list` showed **no row at all** for that path | **OPEN** | — | **Why this is not just R-185 restated:** R-185's mechanism (the installer's Scenario-F arm resolves a pre-existing target without granting) explains a box that NEVER had the grant. This box HAD it and lost it, inside five hours, with the machine up throughout. **Ruled out, each by measurement:** a host reinstall (`uptime` = 12 days); any `pveum`/ACL/`user.cfg` activity in syslog between 04:00 and 10:00 (none); any ACL entry in `/cluster/log` (none). **Correlated, not established:** `host_leaf_changed` at 09:15 and `controller_started` at 09:19 — guest 9201 was reprovisioned nine minutes before the first 403. PVE removes ACLs at `/vms/<vmid>` when a guest is destroyed (`AccessControl::remove_vm_access`, the F-LEAK mechanism); whether any path can take a `/storage/<id>` row with it has NOT been established and is the first thing to check. **Why it matters more than the grant did:** a permission that can vanish silently makes every ACL-based guarantee on these hosts provisional, and the agent's new store-grant probe (v0.123.0) now detects the STATE but says nothing about the TRANSITION. **Worth pairing with:** whether the probe should report a grant it once had and no longer has as a distinct, louder signal than one it never had | CC |
| **R-191** | **Every weekly offsite backup UPLOADS successfully and then FAILS the job on a prune the box is deliberately not allowed to do — on both demo boxes.** Measured on demo-felhom 2026-08-04 06:4906:53: the upload completed (223 s, 629 MiB of 1.874 GiB, **67.2 % reused incrementally**), then `ERROR: prune 'ct/9201': proxmox-backup-client failed: Error: permission check failed - missing Datastore.Modify\|Datastore.Prune on /datastore/felhom-offsite/demo-felhom``ERROR: Backup of VM 9201 failed - error pruning backups``TASK ERROR: job errors`. The hub raised `whole_guest_backup_failed` | **OPEN** | — | **This is R-89's rule not reaching the config.** R-89 moved PBS pruning SERVER-SIDE — *"boxes set `keep_last: 0`, ep0 runs prune jobs; box tokens stay write-only, never widen the grant"*. The token behaves exactly as designed: it refuses. But **both** demo boxes still arm the offsite tier with `keep_last=2 prune_pbs_allowed=true` (`backup_targets: [{target_id: felhom-pbs, cadence_seconds: 604800, keep_last: 2}]`), so every run asks for a prune that must fail. **The data is SAFE and that is why this is not a P1:** the snapshot lands before the prune is attempted; what is wrong is the job's VERDICT and the weekly operator e-mail it produces. **But it is corrosive in the specific way this project keeps finding:** a backup that reports FAILED while succeeding trains the operator to discount `whole_guest_backup_failed`, which is the same alert that would carry a real one — and it is exactly the failure the R-100 corollary warns about, an alarm whose text is true and whose trigger is not the thing you would act on. **Fix is one config line per box** (`keep_last: 0` on the PBS tier) plus whatever writes it on a fresh install; **deliberately NOT applied in this session** — the session was a runbook with an explicit "change nothing, and if a change appears necessary, stop and report" rule, and a retention field on a live backup tier is not a change to slip into an observation run. **Check before fixing:** whether ep0's prune jobs actually cover these two namespaces, or the snapshots simply accumulate once the box stops asking | CC |
| **R-192** | **`offsite_delivery_stuck` tells the operator the opposite of what the detector measured, and the self-heal silently refuses for exactly the reason the message denies.** demo-hp has been e-mailing this daily since 2026-08-03 06:12 UTC: *"one-time password consumed 284h ago and **500 report(s) since carry no offbox target** — the credential is likely burned (apply died between consume and persist). Re-issue delivers a fresh one."* **Measured against the hub's own data: all 500 of those reports DO carry an offbox target** | **OPEN** | — | **What actually happened on that box:** the credential was consumed 2026-07-23 09:53:41 and **applied successfully** — the controller reported an `offsite` object continuously until **2026-08-03 05:59:21 UTC**, then it **vanished at 06:12:19** and has been absent for **108 consecutive reports** since. So this is a **regressed apply**, not a burned credential. **Two distinct defects, and the second explains the first's invisibility.** **(a)** `maybeEmitStuck` builds its message from `status.ReportsSinceConsume` (the TOTAL) while hardcoding the phrase *"carry no offbox target"*, and never consults `status.OffsiteReportsSinceConsume` — which is the field that says the opposite. The recommended action (*Re-issue*) is aimed at a failure mode that did not occur. This is R-100's corollary again: an alarm whose text stopped matching what its verdict counts. **(b)** `maybeHeal` refuses **silently** (`OffsiteReportsSinceConsume != 0`*"regressed-apply shape → operator's call"*, a bare `return` with no log line), so the operator gets a daily e-mail with the wrong story, no heal, and nothing anywhere saying why the heal declined. `offsite_credential_restaged` has **never** fired, on any customer. **The underlying condition is REAL and is the part that matters:** demo-hp currently reports no offsite target at all, i.e. that box's customer app-data has **no off-site copy right now** — and it has been that way since 08:12 CEST on 2026-08-03. A spot check inside the controller container found no restic environment, consistent with the report. **What removed it is not established** and is the first thing to find out. **Fix shape:** the message must state which shape was detected (burned vs regressed) and say what to do for each; the heal's refusal must log its reason; and the regressed shape probably deserves its own event type rather than borrowing the burned one. **Do NOT 'fix' it by widening the heal to restage over a regression** — the guard is right, only mute **CAUSE ESTABLISHED 2026-08-04 (operator confirms no hub-side offsite config change).** The regression is a **guest REBUILD**: at 06:09:40 `host_leaf_changed` (agent re-keyed), at 06:12:18 `controller_started (0.192.0)` — the controller went **0.187.0 → 0.192.0** with a **new config hash** (`1f725a2e843c``744e83d72c80`) — and the report at 06:12:19 is the first without `offsite`. The pre-rebuild object was fully healthy: `escrow_state: escrowed, last_status: ok, last_success 2026-08-03T02:16:39Z, snapshot_count 15, repo_size 40.9 MB`. → **R-193** owns the rebuild half. **AND THE HEAL'S GUARD IS WRONG FOR EXACTLY THIS CASE, which is why the automation that exists to fix it declined.** `maybeHeal` refuses when `OffsiteReportsSinceConsume != 0`, reading that as *"the apply regressed, so it is the operator's call"*. But `CountReportsOffsiteSince` counts the **OLDEST 500 reports since the consume** (`ORDER BY id LIMIT 500`) — for demo-hp all 500 predate the rebuild. **Offbox evidence from before a rebuild is not evidence that the credential still works**, so the guard reads healthy history as a reason not to heal a box that demonstrably cannot apply. The fix is to judge on RECENT evidence (e.g. the latest N reports, or evidence after the newest `controller_started`), not on everything since the consume. | CC |
| **R-193** | **A guest rebuild silently drops the off-site app-data tier, and nothing restages the credential.** demo-hp was rebuilt on 2026-08-03 (controller 0.187.0 → 0.192.0, new config hash, agent leaf re-keyed at 06:09:40). Before it, the offsite tier was healthy and working — `escrow_state: escrowed`, `last_status: ok`, last success **02:16:39Z that morning**, **15 snapshots, 40.9 MB**. After it: no `offsite` object in any of **108** reports, and **no off-site copy of that customer's app data since 08:12 CEST on 2026-08-03** | **OPEN** | — | **Mechanism, fully evidenced.** The restic credential reaches a box exactly once, as a one-time secret. demo-hp's was consumed **2026-07-23 09:53:41**; the rebuilt controller came up with a fresh data volume, no copy of it, and **no way to ask for another** — the hub is the only side that can stage one, and it will not re-stage a consumed secret on its own (the R-71c self-heal would, but it refuses — see R-192). **demo-felhom survived the SAME rebuild by luck, and the contrast is the proof:** its secret was created 2026-07-21 and still **UNCONSUMED**, so when its config hash changed at 07:17:54 and `offsite` dropped for exactly one report, it consumed the staged secret at **07:17:58** and was reporting `offsite` again by 07:19:10. One box had a spare credential staged and recovered in 76 seconds; the other did not and has been unprotected for a day. **That difference was not a design decision — it was an accident of which box happened to have an unconsumed secret lying around.** **Why this is not just "re-issue it":** the remedy (Re-issue) resets the sub-account password via the Hetzner API and, per R-39's record, **rotates the restic password and makes the escrow STALE** — so it needs the recovery-code ceremony re-run, and the continuity of the 15 existing snapshots under the new credential must be VERIFIED, not assumed (`hub v0.60.0` retains superseded escrow, and the orphan guard is move-aside-never-delete). That is an operator act with a customer-facing consequence, so it is not something to fire automatically without deciding the escrow question first. **What to design:** a rebuild is a normal, expected event on these boxes — the offsite tier must survive one, either by the hub restaging automatically when a re-enrolled box reports no offsite (the R-192 guard fix makes this safe), or by the credential being recoverable from escrow at re-bootstrap rather than delivered once and unrecoverable | CC |
| **R-193** | **A guest rebuild silently drops the off-site app-data tier, and nothing restages the credential.** demo-hp was rebuilt on 2026-08-03 (controller 0.187.0 → 0.192.0, new config hash, agent leaf re-keyed at 06:09:40). Before it, the offsite tier was healthy and working — `escrow_state: escrowed`, `last_status: ok`, last success **02:16:39Z that morning**, **15 snapshots, 40.9 MB**. After it: no `offsite` object in any of **108** reports, and **no off-site copy of that customer's app data since 08:12 CEST on 2026-08-03** | **OPEN** | — | **Mechanism, fully evidenced.** The restic credential reaches a box exactly once, as a one-time secret. demo-hp's was consumed **2026-07-23 09:53:41**; the rebuilt controller came up with a fresh data volume, no copy of it, and **no way to ask for another** — the hub is the only side that can stage one, and it will not re-stage a consumed secret on its own (the R-71c self-heal would, but it refuses — see R-192). **demo-felhom survived the SAME rebuild by luck, and the contrast is the proof:** its secret was created 2026-07-21 and still **UNCONSUMED**, so when its config hash changed at 07:17:54 and `offsite` dropped for exactly one report, it consumed the staged secret at **07:17:58** and was reporting `offsite` again by 07:19:10. One box had a spare credential staged and recovered in 76 seconds; the other did not and has been unprotected for a day. **That difference was not a design decision — it was an accident of which box happened to have an unconsumed secret lying around.** **Why this is not just "re-issue it":** the remedy (Re-issue) resets the sub-account password via the Hetzner API and, per R-39's record, **rotates the restic password and makes the escrow STALE** — so it needs the recovery-code ceremony re-run, and the continuity of the 15 existing snapshots under the new credential must be VERIFIED, not assumed (`hub v0.60.0` retains superseded escrow, and the orphan guard is move-aside-never-delete). That is an operator act with a customer-facing consequence, so it is not something to fire automatically without deciding the escrow question first. **What to design:** a rebuild is a normal, expected event on these boxes — the offsite tier must survive one, either by the hub restaging automatically when a re-enrolled box reports no offsite (the R-192 guard fix makes this safe), or by the credential being recoverable from escrow at re-bootstrap rather than delivered once and unrecoverable **RESOLVED ON THE BOX 2026-08-04 (operator-authorised).** Re-issue fired through the designed endpoint (`POST /configs/demo-hp/offsite-reissue`, HTTP 303): hub staged a fresh one-time password at **07:11:51**, the box's config hash moved `744e83d7``5eee0e42`, R-71a's settle-gate reported **GO** (*at/above floor 0.156.0, we are 0.194.0*), the password was **consumed 15 s later at 07:12:06**, and the controller logged *offsite configured for u629488-sub3@…:/home/felhom-repo* at 07:12:09 — the **same sub-account (275124) and the same repo path**, since Re-issue resets the sub-account password and the one-time password is only the transport credential used once to install the box's own SSH key. **THE ESCROW DID NOT RECOVER BY ITSELF — a correction to this session's own first reading.** `escrow_state` went `pending``escrowed` 15 s after the apply and CC inferred an automatic re-escrow; **the operator had run the ceremony**. It needed a human, on BOTH boxes: demo-hp escrowed 07:16:02, demo-felhom (whose offsite re-applied on its own the previous day but whose escrow had been `pending` ever since) escrowed 07:20:28. **A 15-second state change is not evidence of automation** — that is the same class as reading an absent log line as success. **Snapshot continuity is NOT yet established and must not be assumed from the counters:** both boxes report `snapshot_count: 0, repo_size_bytes: 0`, but the run-history keys (`last_run`, `last_status`, `last_success`) are **absent entirely** rather than zeroed — the shape of a controller that has never run an offbox backup in this lifetime, not of an empty repo. demo-hp's pre-rebuild object carried all three plus 15 snapshots / 40.9 MB. **The next scheduled `offbox-backup` (04:15) decides it:** 15+ snapshots ⇒ the repo reattached; 1 ⇒ it started fresh and the old snapshots are orphaned-but-retained. Record the answer here. | CC |
| — | Storage Box **snapshots** on `storage-box-pool-1` — plan SET (daily 00:00, keep 7) but **0 taken yet** | WATCHING | first run tonight 00:00 | Confirm `size_snapshots > 0` tomorrow; until then the mitigation is armed, not proven | CC |
| — | `PBS-storage-1` (u629193, box 611421) still `status=active`, 19.9 MB | WAITING-ON-OPERATOR | operator console | Delete the box | operator |
| **R-90** | ~~ep0 RAM headroom — 4 GiB swap survived its first reboot 2026-07-27; 3.8 GB RAM unchanged~~ | **CLOSED — the operator rescaled ep0 to a CX33 on 2026-08-03** | — | **MEASURED ON THE BOX, not read from an invoice:** `felhom-hetzner` reports `Mem: 7757` MB total (**8 GB**, was 3.8) and `nproc` **4**. **The interim lever survived and was checked rather than assumed** — a resize is a stop/start, so "the swapfile is still there" was an assumption until measured: `/swapfile`, 4 GiB, dated `Jul 27 14:40`, **active** (`swapon --show``/swapfile file 4G 0B -2`), 0 B in use on an idle box. **THE 40 GB LOCAL DISK DID NOT CHANGE** and must not be "corrected" alongside the RAM: `/` is 38 G, 58% used. This was a CPU/RAM resize only, so every disk figure in the runbooks still stands — the separate 98 G volume at `/mnt/pbs-datastore` (R-82 P0.3) is unaffected. **Why this was BLOCKED and no longer is:** the row recorded CX33 as *"confirmed unavailable even powered OFF"* — the Cost-Optimized line's limited availability, not a power-state problem. It became available and the operator took it. **Documentation corrected** (`RUNBOOK-ep0-datastore-volume`, `RUNBOOK-pbs-prune-serverside` ×2, `runbooks/offsite-endpoint.md` ×2, `runbooks/target-selection.md`) and **audit/evidence documents ANNOTATED, not revised** (`SPIKE-connectivity-wireguard-2026-07-03`, campaign-10 `phaseA-journal`) — they record what was true when written and that is their value. **Still open and still the operator's, deliberately untouched:** `target-selection.md`'s *"D-d did not name ep0 either way. Confirm it explicitly."* | — |