From 65409aecd109951916a5fd003b10ef80b8a6274d Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Mon, 27 Jul 2026 16:27:31 +0200 Subject: [PATCH] docs: R-88 Part 1 shipped; Phase 0 root cause; R-97 minted MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit R-88 split: Part 1 (the failure breaker) SHIPPED in controller v0.176.0 and live on both boxes; Part 2 (unknown != never) stays OPEN and is agent-side. Phase 0 established the root cause at source: newestArchiveOn's (time.Time, bool) signature cannot represent 'unknown', so a storage read ERROR collapses into a positive 'no successful backup recorded yet'. The errored and genuine-never paths are byte-identical on the wire, which is why Part 2 cannot be done controller-side. R-97: the whole-guest backup tier has no failure signal to the hub at all — internal/quiesce never imports internal/notify, so three failed backups and three app-stack outages produced zero backup_failed events. Its only trace was a customer-tier Hungarian app_start_failed for an app the backup itself had stopped. --- documentation/backlog/OPEN-ITEMS.md | 9 +++++---- documentation/backlog/ROADMAP.md | 5 +++-- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/documentation/backlog/OPEN-ITEMS.md b/documentation/backlog/OPEN-ITEMS.md index 9397075..fe9be50 100644 --- a/documentation/backlog/OPEN-ITEMS.md +++ b/documentation/backlog/OPEN-ITEMS.md @@ -8,7 +8,8 @@ State: `BLOCKED` · `READY` · `WAITING-ON-OPERATOR` · `WATCHING`. Every row ha | ID | What | State | Blocked on | Next action | Owner | |---|---|---|---|---|---| -| **R-88** | Unreachable backup target reads as *no backup exists* → quiesce loop, no backoff, maintenance window bypassed | **READY #1** | — | Make an unreachable read UNKNOWN; fix the `AgeSecs==nil` window bypass in the same slice | CC | +| **R-88a** | ~~Failing backup re-quiesces every 5 min, no backoff~~ | **SHIPPED** (controller v0.176.0, 2026-07-27) | — | Live on both boxes; breaker 15m→4h, per-tier, never permanent | — | +| **R-88b** | `/backup/due` cannot say *unknown* — "read errored" and "never backed up" are byte-identical, so nil still bypasses the window gate | **READY #1** | — | Agent wire change: give unknown its own representation; compat rule both ways + MinAgent floor | CC | | **R-95** | restic offsite credential **can delete** (`readonly=False`, `forget --prune` runs from the box); SFTP cannot express append-only | **READY #2** | — | Snapshot plan as the stopgap (row below), then split prune off-box or move to REST `--append-only` | CC | | **R-94** | Hub hands out host-install `1.19.0`; `1.20.0` is what carries R-82's backup default | **READY #3** | — | Bump `configs.go:28`, and stop hand-syncing a version constant across repos | CC | | **R-86** | Restore-tests are interval-scheduled, not backup-aligned | **READY #4** | R-90 (ep0 headroom) informs cadence | Trigger a tier ~24 h after **its own** newest archive | CC | @@ -27,9 +28,9 @@ State: `BLOCKED` · `READY` · `WAITING-ON-OPERATOR` · `WATCHING`. Every row ha ## Why the READY rows rank this way -1. **R-88** — the only item causing *active harm*: it stops every customer app stack every 5 minutes, - with no backoff, and the `AgeSecs==nil` path also disables the maintenance-window gate, so it runs - in business hours. Its trigger is a PBS read failure, which R-90 shows is live. +1. **R-88b** — the loop itself is fixed (R-88a, v0.176.0), so the active harm is gone; what remains is + that an unknown still fires the safety valve, so a read failure can take **one** out-of-window + quiesce. Bounded now, but it is the fourth appearance of this class and the only one still open. 2. **R-95** — the largest *data* exposure: the tier holding the customer's documents and photos is the one whose credential can delete, and the mitigation is a console click nobody has made. 3. **R-94** — a one-line constant, but until it moves every hub-driven install gets the pre-R-82 diff --git a/documentation/backlog/ROADMAP.md b/documentation/backlog/ROADMAP.md index 39087e2..42fa345 100644 --- a/documentation/backlog/ROADMAP.md +++ b/documentation/backlog/ROADMAP.md @@ -116,14 +116,15 @@ | R-85 | **The DR tier must be restore-tested UNATTENDED, and its failure must be HEARD** | M | **Code SHIPPED (agent v0.104.0 + hub v0.77.0, 2026-07-27); rotation NOT YET OBSERVED LIVE** | R-82 proved a PBS restore round-trip **by hand**. Three defects kept the unattended path from covering it, each verified at source: **(a)** `buildRestoreTestScheduler` took `cfg.Backup.BackupTarget()` and built ONE runner on it, so the offsite tier's archives were never candidates; **(b)** the `Spec` was an immediately-invoked function evaluated ONCE at daemon start, so nothing tier-varying was expressible and any storage-type/config change stayed stale until restart; **(c)** a failed restore-test was a `[WARN]` log line with **no event, no notification, no gauge** — true for the LOCAL tier that was already being tested, so the loudest DR signal this system produces was inaudible. (c) is the one that mattered: rotating tiers without it would only mean two tiers can fail silently instead of one. **Selection ruling (operator, 2026-07-26): oldest-first (Option 1)** — never-proven sorts first, which is where the offsite tier starts; no new cadence knob. The per-tier last-proven timestamp is now reported **so the achieved interval can be MEASURED before anyone decides whether a knob is needed** — measure, then configure, not the reverse. **Shipped:** per-run `SpecBuilder`; `PickRestoreCandidateOn` (a tier with no archive NO-OPS, never fails); persisted `RestoreTestState` (rotation survives a restart — credit only on SUCCESS, or a permanently failing tier looks freshly proven); `backup.InFlight`, the host-wide one-heavy-op gate shared with the backup path (a LINK concern, not a lock one — an offsite restore pulls multi-GB over the tunnel a backup pushes one); and hub `restore_test_failed` / `restore_test_stale`, kept **distinct** and anchored on R-81's verdict structure, operator-tier only. **NOT yet proven:** rotation has not been observed selecting both tiers across consecutive unattended cadences — a multi-day window at a 24h cadence. Manual restore-proof IS proven (R-82). | | R-86 | **Backup-ALIGNED restore-test scheduling — test a tier ~1 day after ITS OWN backup** | S | **NEXT — operator ruling 2026-07-27** | R-85 schedules restore-tests on a free-running INTERVAL and rotates oldest-proven-first. That cannot express *"the day after the PBS backup"*: any fixed offset drifts against the backup schedule, so alignment would be luck rather than design. **The ruling:** weekly per tier (daily is overkill), timed **~1 day after that tier produced a new backup** — so the gap between an archive being written and being proven stays small, and a tier is never proven against an archive about to be pruned (offsite retention is 2 weeks). **Shape:** trigger a tier from **its own last successful backup** rather than a clock — test tier X once its newest archive is ~24 h old and not yet proven. Self-aligning when a backup runs late, and it naturally stops testing a tier that has stopped producing backups (today an interval keeps re-testing the same stale archive). Needs the scheduler to consult per-tier backup times (already available: `BackupRunner.NewestArchiveTime`, R-84) alongside `RestoreTestState` (R-85). **Interim in force:** `restore_test_cadence_seconds = 302400` (3.5 d) on both boxes — oldest-first over two tiers lands each tier ~weekly, which matches the cadence half of the ruling but NOT the alignment half. | | R-87 | **The restic (app-data offsite) tier is NEVER restore-tested** | M | idea — surfaced 2026-07-27 while closing R-85 | **R-85 covers whole-guest vzdump tiers only** (`local`, `felhom-pbs`); the agent has no restic surface at all. restic is the CONTROLLER's app-data offsite backup to the Hetzner Storage Box, a separate mechanism — so the tier that is arguably most important to a customer is the one nothing verifies. It is the only tier that survives losing the box **and** carries their actual app data: the whole-guest snapshot deliberately excludes the bind-mounted data drives (`/mnt/felhom-drives`). Restore code exists and has been exercised BY HAND (the immich destroy-and-recover drill, PROVEN-LIVE), but nothing tests it unattended — **exactly the state PBS was in before R-85: it works when someone tries it, and nobody would know if it stopped.** Needs its own design: a restic restore-test is controller-side, has no scratch-guest analogue, and would verify into a scratch dir rather than a booted guest, so R-85's machinery does not transfer. | -| R-88 | **An UNREACHABLE backup target reads as "no backup exists" → the agent fires a doomed backup at it** | S | idea — observed live 2026-07-27 | **The R-81 class (absence-is-not-failure), reappearing one layer down in the AGENT's due-check.** R-84 replaced the in-memory `Store` with storage ground truth (`NewestArchiveTime`), and fails safe on a read error by *falling back to the in-memory record* — "never fake freshness, never suppress". That fallback is correct in isolation but wrong in the one composition where it actually runs: **a cold store plus an unreachable target.** After a restart the in-memory record is empty, so the fallback answers *no backup has ever been recorded* → tier due → the agent fires a backup at the very storage it just failed to read. **Observed:** `felhom-agent` restarted on demo-felhom at 07:02:57 UTC; `local-api: could not read the backup storage for the due-check — falling back to the in-memory record` (vmid=9201 target=felhom-pbs); 11 s later `vzdump 9201 → felhom-pbs` failed with `could not activate storage 'felhom-pbs' … Can't connect to 10.77.0.1:8007 (Connection refused)`. The offsite PBS service was down at the time — so the trigger was real, not synthetic. **NOT bounded, and it also DISABLES the business-hours protection — an availability fault, not a logging nuisance.** The first reading ("fails in ~0 s, so the cost is one spurious event per restart") was wrong on both halves, and a second reading ("it stopped after three tries, so something limits it") was wrong too — the live run stopped after three only because the storage came back. **Verified in code: there is no limiter.** `internal/quiesce` holds no failure counter, no backoff, no breaker, no attempt budget; `runOnce` keeps no state between ticks, and the driver is a plain 5-minute `time.Ticker` (`quiesce.go:149`, default `quiesce.go:107-109`). Had the target stayed down, the loop would have continued indefinitely. +| R-88 | **An UNREACHABLE backup target reads as "no backup exists" → the agent fires a doomed backup at it** | S | **Part 1 SHIPPED (controller v0.176.0, 2026-07-27); Part 2 OPEN (agent wire change)** — **Part 1** added the failure breaker: consecutive failures tracked per TARGET, backoff `15m→30m→1h→2h→4h` capped, reset on success, gating the QUIESCE rather than the backup so no stack is stopped for a doomed attempt. Never permanent (the cap bounds the retry interval — a latched breaker is a silent backup outage), never global (a broken offsite tier cannot suppress a healthy local one), never applied to `TriggerNow`, and `stillRunning` is not a failure. In-memory on purpose: forgetting a backoff costs one attempt, persisting one could outlive the fix. **Part 2 is agent-side and needs a wire change** — see the P0 finding below. Live on both boxes; the loop reproduction is UNIT-TEST ONLY (reproducing it live would need PBS taken down on ep0, which has no swap). | **The R-81 class (absence-is-not-failure), reappearing one layer down in the AGENT's due-check.** R-84 replaced the in-memory `Store` with storage ground truth (`NewestArchiveTime`), and fails safe on a read error by *falling back to the in-memory record* — "never fake freshness, never suppress". That fallback is correct in isolation but wrong in the one composition where it actually runs: **a cold store plus an unreachable target.** After a restart the in-memory record is empty, so the fallback answers *no backup has ever been recorded* → tier due → the agent fires a backup at the very storage it just failed to read. **Observed:** `felhom-agent` restarted on demo-felhom at 07:02:57 UTC; `local-api: could not read the backup storage for the due-check — falling back to the in-memory record` (vmid=9201 target=felhom-pbs); 11 s later `vzdump 9201 → felhom-pbs` failed with `could not activate storage 'felhom-pbs' … Can't connect to 10.77.0.1:8007 (Connection refused)`. The offsite PBS service was down at the time — so the trigger was real, not synthetic. **NOT bounded, and it also DISABLES the business-hours protection — an availability fault, not a logging nuisance.** The first reading ("fails in ~0 s, so the cost is one spurious event per restart") was wrong on both halves, and a second reading ("it stopped after three tries, so something limits it") was wrong too — the live run stopped after three only because the storage came back. **Verified in code: there is no limiter.** `internal/quiesce` holds no failure counter, no backoff, no breaker, no attempt budget; `runOnce` keeps no state between ticks, and the driver is a plain 5-minute `time.Ticker` (`quiesce.go:149`, default `quiesce.go:107-109`). Had the target stayed down, the loop would have continued indefinitely. Each attempt runs the **full quiesce cycle**, so every customer app stack is STOPPED and RESTARTED for a backup that cannot succeed. Measured on demo-felhom: `07:07:58 quiescing 4 stack(s): [bookstack calibre-web docmost immich]` → `07:08:17 unquiescing (backup failed)` → `07:08:45 failed` — **~19 s of app downtime per cycle (~50 s per full cycle), every 5 minutes.** **The amplifier, and the part worth designing against:** the agent answers `Due: true, Reason: "no successful backup recorded yet", AgeSecs: nil`, and that **nil age does double duty**. `scheduledRunAllowed` (`quiesce.go:466-480`) returns `true` whenever `lastAgeSecs == nil` — *"no recorded backup yet — never withhold the first one"* — so the same nil that makes every poll due **also bypasses the time-of-day gate** `[W+2h, W+6h)`. On the live box the gate was `[04:30, 08:30)` and the cycles ran at 09:02–09:12 Budapest, i.e. **outside the backup window entirely**. So the fault stops customer apps every 5 minutes *at any hour, including business hours* — the one protection specifically built to prevent that is switched off by the same missing value. A safety valve written for a genuine first-ever backup is being triggered by an unreachable storage read, which is not the same thing at all. -Self-resolves the moment the target answers (the storage read succeeds, sees the archive, tier stops being due) — which is why it can hide indefinitely: it needs an offsite outage to appear at all. **Shape:** distinguish *storage unreachable* from *storage readable and empty*. Unreachable is UNKNOWN — defer the due-verdict rather than resolving it either way, exactly as R-81 made the hub do with a missing report. Only a target that is reachable AND has no archive is genuinely due. **Fix the window bypass in the same slice:** `AgeSecs == nil` must stop meaning "run now regardless of the hour". Either the agent distinguishes *never backed up* from *cannot tell* in what it reports, or `scheduledRunAllowed` gates on the former only — otherwise any future nil-age path re-opens the same hole. Note this does NOT weaken R-84's fail-safe intent: a tier whose storage is merely slow or briefly unreadable should still err toward backing up — it is specifically the **cold-store + unreachable** pair that must defer, because there the fallback has no information at all, only an empty default that looks like a fact. | +Self-resolves the moment the target answers (the storage read succeeds, sees the archive, tier stops being due) — which is why it can hide indefinitely: it needs an offsite outage to appear at all. **PHASE-0 ROOT CAUSE, established at source 2026-07-27 — it is AGENT-side, case (a).** The storage read **errored** (`could not read the backup storage for the due-check … err=…` at 09:02:57/09:07:58/09:12:57 CEST), so this was never an empty-success. The failure is a **type boundary**: `newestArchiveOn` (`localapi/server.go:1095-1111`) documents *"Errors and unsupported services degrade to unknown, never to 'no backup'"* — but its `(time.Time, bool)` signature **cannot represent unknown**, so an error and a genuinely-empty storage both collapse to `(zero, false)`, and `handleBackupDue` (`server.go:934-941`) then emits a POSITIVE claim: `Due: true, Reason: "no successful backup recorded yet", AgeSecs: nil`. The fail-safe that *does* exist — `targetStoragePresent`'s "a storage-view error must never be read as 'not there'" (`server.go:1131-1151`) — answers a different question (does the storage exist) and behaved correctly. **Decisive for scoping: the errored path and the genuine-never path are BYTE-IDENTICAL on the wire** — same `Due`, same `Reason` string, same nil `AgeSecs` — so the controller has nothing to discriminate on and Part 2 CANNOT be done controller-side. **Two further P0 findings:** the agent restarted **4× on 2026-07-27** (07:36:39, 07:54:06, 08:50:16, 11:31:52 CEST) — all deliberate (`NRestarts=0`, `Restart=on-failure`, `Result=success`), zero self-update — so the trigger is armed by ordinary operator/config work far more often than "only when ep0 is down"; and **the loop alerted NOBODY** — zero `backup_failed` events despite the hub allowlist carrying that type, because **`internal/quiesce` does not import `internal/notify` at all**. Its only trace was `07:13:27 info app_start_failed "Telepített alkalmazás nem fut: BookStack"` — a customer-tier, Hungarian, info-severity SYMPTOM of the third cycle catching BookStack mid-restart. **The whole-guest backup tier R-82 built has no failure signal to the hub → its own item.** **Shape:** distinguish *storage unreachable* from *storage readable and empty*. Unreachable is UNKNOWN — defer the due-verdict rather than resolving it either way, exactly as R-81 made the hub do with a missing report. Only a target that is reachable AND has no archive is genuinely due. **Fix the window bypass in the same slice:** `AgeSecs == nil` must stop meaning "run now regardless of the hour". Either the agent distinguishes *never backed up* from *cannot tell* in what it reports, or `scheduledRunAllowed` gates on the former only — otherwise any future nil-age path re-opens the same hole. Note this does NOT weaken R-84's fail-safe intent: a tier whose storage is merely slow or briefly unreadable should still err toward backing up — it is specifically the **cold-store + unreachable** pair that must defer, because there the fallback has no information at all, only an empty default that looks like a fact. | | R-89 | **Retention is a COMMERCIAL attribute — it belongs to the hub, not to ep0 or a box** | M | idea — operator ruling 2026-07-27, first increment SHIPPED same day | **Ruling (2026-07-27):** retention is a per-customer *commercial* attribute (a paid tier may buy longer retention), so the **hub owns the policy** and ep0 merely executes it. Execution stays **server-side**: a reconciler writes a **PBS prune job** and PBS's own scheduler runs it, so hub downtime leaves the last-known policy running rather than silently stopping retention. **Increment 1 SHIPPED 2026-07-27** (`runbooks/RUNBOOK-pbs-prune-serverside-2026-07-27.md`): boxes no longer attempt prune (`keep_last: 0` → `allowPBSPrune=false`, config only — no code, no grant), and per-namespace prune jobs run on ep0 daily 03:30 UTC (`keep-last 2`), dry-run gated and verified `TASK OK`. This also closed a live defect — **every** demo-hp PBS backup since the tier was created on 07-26 had reported `job errors` while the data landed correctly, because `DatastoreBackup` grants `Datastore.Backup` but not `Datastore.Prune`; a tier that cries wolf on every success makes a genuine failure invisible, which is exactly what happened during the 07-27 migration window. **Remaining work:** retention becomes a per-customer attribute on the hub — a **policy** (keep-last/daily/weekly/monthly), NOT a bare number, since a paid tier will want "12 weekly + 6 monthly"; a reconciler converges it into the ep0 prune job in the same descriptor-and-converge shape as `pbs_dr`. **SECURITY PROPERTY TO PRESERVE — do not "fix" a future prune error by widening the grant:** box tokens stay **write-only** (`DatastoreBackup`), never `DatastorePowerUser`/`DatastoreAdmin`. A compromised box must not be able to delete its own offsite backups — that is the scenario offsite DR exists to survive. **PARALLEL QUESTION, unanswered and arguably the more urgent half: does the restic key on `storage-box-pool-1` (`u629488`) have DELETE rights?** If so the daily app-data offsite tier carries the identical exposure, and restic's **append-only** mode is the equivalent answer. **Rule once for both tiers.** Flips the capability-map row for offsite retention (currently: retention configured but unenforceable) | +| R-97 | **The whole-guest backup tier has NO failure signal to the hub — `internal/quiesce` never notifies** | S | idea — found by R-88 Phase 0, 2026-07-27 | On 2026-07-27 three whole-guest backups failed and three quiesce cycles stopped and restarted every customer app stack, and **not one `backup_failed` event reached the hub.** It is not the allowlist — the hub already carries `backup_failed` and `backup_completed` (they are emitted by the controller's *app-data* backup path). The cause is that **`internal/quiesce` does not import `internal/notify` at all**: the tier R-82 built has no route to the hub, so a whole-guest backup can fail indefinitely in silence. The loop's only trace was `app_start_failed` — **info** severity, **Hungarian**, on the **customer** channel — telling the customer BookStack was down (it had been caught mid-restart by the third cycle) without saying why, during an outage the system itself caused. So the one signal that did fire was both the wrong tier and the wrong story. **Shape:** emit `backup_failed`/`backup_completed` from `quiesceAndPollTiers` naming the TIER, operator-tier; and decide whether a quiesce-induced restart should suppress `app_start_failed` the way R-164's deliberate-stop filter does — an app the backup stopped on purpose is not a fault. R-88's breaker bounds the repetition but changes nothing about the silence | | R-95 | **The restic offsite tier's credential CAN DELETE — R-89's "parallel question", now ANSWERED** | M | idea — established read-only 2026-07-27 | **The exposure closed on the weekly PBS tier is fully open on the daily restic tier**, which holds the customer's actual documents and photos and is the only tier that survives losing the box. Established without mutating anything: **(1) Identity** — a per-customer *subaccount* on `storage-box-pool-1` (box 611714, bx11, `u629488`): `u629488-sub1` home `felhom-demo-felhom`, `sub2` peti-felhom, `sub3` demo-hp, each labelled `felhom-customer`. Auth is an **SSH key stored ON THE BOX** (`…/felhom-controller-data/_data/data/offbox/ssh_key`, 0600, beside `repo_password` + a pinned `known_hosts`) — customer-side, not hub-side, so a compromised guest holds it. **(2) Read-write: YES** — the API reports **`readonly=False` on all three subaccounts**, and it is not merely latent: the controller runs `restic forget --group-by host,tags --keep-daily 7 --keep-weekly … --prune` **from the box** (`backup/offbox.go:984`, also `:1070`). Delete rights are exercised on every run. **(3) Append-only: NO, and not expressible** — the repo is built as `sftp:` (`offbox.go:482`); restic's append-only mode requires the **REST server** backend, which plain SFTP cannot provide. **(4) A zero-code mitigation exists and is unused:** the box type carries `snapshot_limit=10` and the API reports `snapshot_plan=null` with **0 snapshots** and `size_snapshots=0`. Hetzner Storage Box snapshots are taken **server-side, outside the SFTP namespace** — an SFTP subaccount cannot delete them — so they are a genuine immutability layer at no extra cost and with no code change. **Rule once for both tiers, per R-89.** Options, cheapest first: enable a snapshot plan (operator click, immediate); split backup-write from prune so pruning runs somewhere the box cannot reach; or move the repo to restic's REST server with `--append-only`. Flips the capability-map row for offsite immutability | | R-94 | **The hub hands out host-install `1.19.0` while `1.20.0` is what ships R-82's backup default** | XS | idea — found 2026-07-27 | `hub/internal/web/configs.go:28` pins `const hostInstallVersion = "1.19.0"`, and that constant renders the customer page's install command (`configs.go:487` `ScriptVersion`). `scripts/felhom-host-install.sh:187` is `SCRIPT_VERSION="1.20.0"` — the version R-82 shipped to default a fresh box to **local-daily + offsite-weekly**. So a new install driven from the hub still gets the **pre-R-82** default. This is the same constant hub `v0.73.2` existed to sync (→1.19.0); it went stale again one installer release later, which is the actual finding: **a hand-synced version constant in a second repo drifts every time the first one ships.** v0.73.2 itself is NOT an undeployed artifact — its content is inside the live 0.77.0. Related to R-82's "REMAINING GATE" note, but that gate is about the fleet flip; this is the hub simply pointing at the older script | | R-90 | **ep0 has 3.8 GB and NO swap — it OOMs under a restore-test, and that gates R-86** | S | BLOCKED on Hetzner CX33 availability (operator, 2026-07-27) | Verified read-only: `Swap: 0B`, nothing in `/etc/fstab`, no swap unit, no `/swapfile` — **swap was never added.** On 2026-07-27 06:58:12 a global OOM fired while `proxmox-backup-proxy` held a 3.2 GB peak serving a 14.46 GB restore-test read and the datastore-migration `rsync` held 1.9 GB; the kernel killed the rsync and PBS stopped serving for ~15 minutes. That outage is what exposed **R-88** downstream. Still exposed today: 3.8 GB, no swap, one kill on record. **This gates R-86** — backup-aligned restore-testing puts a multi-GB read on this box *on a schedule*, so the headroom question must be settled before that lands. Interim lever if CX33 stays unavailable: a swapfile, which needs no console |