R-193: a guest rebuild silently drops the offsite tier; R-192 cause established
gates / gates (push) Successful in 8s
gates / gates (push) Successful in 8s
Operator confirms no hub-side offsite config change, so the regression was not an action. Evidence: demo-hp's controller went 0.187.0 -> 0.192.0 at 06:12:18 with a new config hash and the agent re-keyed its leaf three minutes earlier — a guest rebuild. The last pre-rebuild report shows the tier fully healthy: escrowed, last success 02:16:39Z, 15 snapshots, 40.9 MB. No offsite object in the 108 reports since. Mechanism: the restic credential is delivered once. demo-hp consumed its secret on 2026-07-23; the rebuilt controller has no copy and no way to request another. demo-felhom survived the SAME rebuild only because its secret was still unconsumed — it consumed it four seconds after its config hash changed and was reporting offsite again 76 seconds later. That difference was luck, not design. Also sharpens R-192: the self-heal's guard refuses when any report since the consume carried an offbox target, but that query reads the OLDEST 500 reports — all of which predate the rebuild. Healthy history before a rebuild is not evidence the credential still works, which is why the automation that exists for this case declined to act.
This commit is contained in:
@@ -20,13 +20,16 @@ Proven end to end on real hardware.
|
||||
|
||||
## What's broken
|
||||
|
||||
- **One demo machine has no off-site copy of its app data, and has not since yesterday morning.** The
|
||||
second demo machine (`demo-hp`) stopped reporting an off-site backup at 08:12 on 3 August and has
|
||||
not reported one in 108 check-ins since. The daily email you are getting about it is right that
|
||||
something is wrong, but **its explanation is wrong** — it says the password was never applied, when
|
||||
in fact it was applied on 23 July and then stopped working eleven days later. The automatic repair
|
||||
declines, correctly, because it can see it is a different problem — but says nothing about why.
|
||||
*(R-192)*
|
||||
- **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)*
|
||||
- **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)*
|
||||
- **The weekly off-site backup reports FAILED although it worked.** It uploads correctly and then
|
||||
trips on a tidy-up step it is deliberately not allowed to perform, so the job ends in an error and
|
||||
you get an email. The backup itself is safe and on the endpoint. Both demo machines do it; one
|
||||
|
||||
@@ -35,7 +35,8 @@ State: `BLOCKED` · `READY` · `WAITING-ON-OPERATOR` · `WATCHING`. Every row ha
|
||||
| **R-189** | **A passing restore-test can be invisible to the hub forever — and R-86 made that window a week instead of a day.** The agent reports `restore_tests[]` from `internal/backup.Store`, which is **in-memory** (its own comment: *"lost on restart; the cadence re-populates"*), and the hub's report interval is 900 s. An agent restart inside that window drops the result. That used to self-heal within 24 h because the next cadence re-tested the same tier; **under per-archive due-ness the agent will NOT re-test a proven archive**, so the hub can stay ignorant of a proof until the NEXT archive generation — a week on the offsite tier. **Observed live, 2026-08-03:** the 15:25:14 PASS on `felhom-pbs` (a real 14.5 GB offsite restore) reached **no** host-report — the hub logged `0 restore-tests` at 15:28:00 and 15:32:14 — because the agent was restarted at 15:27:57 for the v0.121.1 deploy, 2 m 43 s after the run and before the next report | **CLOSED — SHIPPED + PROVEN-LIVE 2026-08-03** (agent **v0.122.0**) | — | **The persisted proof already exists and is not reported.** `RestoreTestState` (on disk, per tier, R-86: with the archive id) survives exactly this, and `RestoreTestState.Snapshot()` carries the doc comment *"for the host-report gauge"* — **and has no production caller at all** (grep, 2026-08-03). That is this project's own *seam built but never wired* class, fifth instance, and a comment asserting an invariant with no test pinning it, both in one method. **Severity is bounded, and worth stating so it is not over-ranked:** the hub scans its retained window, archives keep arriving, and R-86's per-tier window for the offsite tier is 12 days against a 7-day archive rhythm — so ONE lost report is tolerated. What is not tolerable is that the loss is **silent** and that the box will not repeat the work. **Fix shape:** report the persisted per-tier proof (target, archive, proven_at) alongside the in-memory latest run, and let the hub's `lastProvenPerTier` read it — a report-contract change, so it touches `internal/hub/report.go` + `contract_test.go` + the hub's checker, and it is a spec, not a one-liner **FIXED.** `RestoreTestState` now stores the **tier** and what was **verified** beside the archive (recorded at proof time, from the run's own result — deriving them later would need a storage lookup that can fail on the one path where failing means mislabelling a proof), exposes `ProvenRestoreTests`, and `Collector.SetProvenRestoreTests` merges it with the in-memory result. **Merge rule: one entry per tier, newest by `TestedAt` wins** — a fresh failure beats a stored success (the failure is the news and lives nowhere else), a stored success beats a stale in-memory entry after a restart, and a tier never appears twice (two entries would read at the hub as two tests). An unparseable timestamp counts as OLDER, so a malformed entry cannot displace a good one. **It refuses to lie:** a record missing the archive OR the tier produces NO entry, and run mechanics (scratch VMID, duration) are not re-invented — an absent duration is not a claim, a fabricated one would be. **The asymmetry is now written where it will be read:** only successes are persisted, because a success SUPPRESSES future work (a proven archive is never re-tested, so a lost proof leaves the box quietly less tested than it believes) while a failure CAUSES future work and heals itself at the next evaluation. **`Store`'s comment was corrected in place** — *"lost on restart; the cadence re-populates"* was true under a timer and became false the moment R-86 shipped; leaving it is how the next reader concludes this is handled. **The seam that had no caller is now pinned by an AST test** (`TestMainWiresTheDurableRestoreTestProof`), because `Snapshot()` claimed a *"host-report gauge"* in its doc comment for weeks with nothing calling it. **MIGRATION, stated because it is visible on the live box:** a pre-R-189 record carries an archive but no tier and is therefore NOT reportable — upgrading does not retroactively make an old proof visible to the hub; the tier's next real proof fills it in. Observed on demo-felhom immediately after the upgrade: still `0 restore-tests` until a fresh run. | CC |
|
||||
| **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:49–06: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 | 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 |
|
||||
| — | 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."* | — |
|
||||
|
||||
Reference in New Issue
Block a user