docs: seam sweep + live outage validation report
Seam sweep: TieredBackend was the FIRST, not the only one. BackupArchiveLister has the identical silent-degrade shape and a worse blast radius (it degrades to the pre-R-84 in-memory-only behaviour), and no compile-time witness existed in production code anywhere in either repo. No defect found, so no version bump and no deploy — the witnesses are guards, proven by breaking a signature and watching go build fail where it previously passed. Live outage: age_state=unknown captured on real hardware for the first time, with demo-felhom's local tier genuinely due throughout — the controller deferred and zero app stacks were stopped. The R-88 breaker did NOT arm and no whole_guest_backup_failed travelled, because felhom-pbs was not due; recorded as conditions-did-not-arise rather than claimed as coverage. Post-boot: the volume changed device name (sdb->sda) across the reboot and the mount survived only because fstab uses by-id. That was never tested before.
This commit is contained in:
@@ -1,316 +1,147 @@
|
||||
# REPORT — R-80 → R-85: from a false alarm to an audible DR tier (2026-07-26 → 27)
|
||||
# REPORT — closing the backup arc: seam sweep + live outage validation (2026-07-27)
|
||||
|
||||
One long session. It began as a diagnostic into a nightly alarm and ended with the offsite DR tier
|
||||
being **restore-proven unattended, with its failure audible**. Five roadmap items, four artifacts.
|
||||
**Overwritten** per the standing rule. **No version shipped** — the sweep found no defect, so the
|
||||
witnesses are compile-time-only source changes riding the next release. Agent `9842c52`→`0236553`,
|
||||
controller `ca013c8`→`8f46495`. Live fleet unchanged: hub v0.79.0, agent v0.105.0, controller v0.178.0.
|
||||
|
||||
| Repo | From → To |
|
||||
## Part 1 — the seam table
|
||||
|
||||
Every optional-capability type assertion across all four repos. `StackDataProvider`, `BackupReporter`
|
||||
and `RestoreTestReporter` are **not** in this table: they are interface-typed struct *fields*, which
|
||||
the compiler already enforces at assignment. The dangerous shape is `x.(Interface)`.
|
||||
|
||||
| Interface | Asserted at | On failure | Silent? | Witness now |
|
||||
|---|---|---|---|---|
|
||||
| `quiesce.TieredBackend` | `tiers.go:109` (`resolveDueTiers`) | falls back to the untargeted single-tier path | **SILENT** | ✅ moved to production |
|
||||
| `quiesce.TieredBackend` | `quiesce.go:375` (`allTiersForManualRun`) | manual run covers only the untargeted tier | **SILENT** | ✅ same witness |
|
||||
| `quiesce.TieredBackend` | `tiers.go:191`, `:199` | **unchecked — would panic** | no (loud) | ✅ same witness |
|
||||
| `localapi.BackupArchiveLister` | `server.go:1155` (`newestArchiveOn`) | degrades to `archiveAbsent` = pre-R-84 in-memory-only | **SILENT** | ✅ added |
|
||||
| `agentapi.AgentVersionReporter` | `features.go:157` | version gate → live probe | silent, benign (both decide correctly) | ✅ added |
|
||||
| anonymous `GuestMemory` iface | `features.go:86` | returns `errNoMemoryProbe` → `SupportUnknown` | **no** — distinct error | n/a (anonymous) |
|
||||
|
||||
**Was `TieredBackend` the only one, or the first one? It was the first one.**
|
||||
`BackupArchiveLister` has the identical shape and a worse blast radius: a silent degrade to
|
||||
`archiveAbsent` is the R-84 bug returning — a cold store after a restart reading as "no backup ever" —
|
||||
with nothing in any log. It had **no witness of any kind**, and in fact **zero compile-time witnesses
|
||||
existed in production code anywhere in either repo** before today.
|
||||
|
||||
**No defect found.** Every implementation satisfies its interface today, so per the task's rule there
|
||||
is no version bump and no deploy. What was missing was the *guard*, not the behaviour.
|
||||
|
||||
**The guard is proven, not assumed.** Breaking `BackupRunner.NewestArchiveTime`'s signature now fails
|
||||
`go build`:
|
||||
|
||||
```
|
||||
cmd/felhom-agent/seam_witnesses.go:28:38: *backup.BackupRunner does not implement
|
||||
localapi.BackupArchiveLister (wrong type for method NewestArchiveTime)
|
||||
```
|
||||
|
||||
Before the witness, that same break compiled and vetted clean. The controller's witness also **moved
|
||||
out of a `_test.go` file** — a test-file witness fires on `go test`/`go vet` but not on `go build`
|
||||
alone, which is exactly the path the R-88 Part 2 near-miss would have taken.
|
||||
|
||||
## Part 2 — the live outage
|
||||
|
||||
Pre-flight cleared: 0 tasks in flight on ep0, 0 backup/restore processes on either box (counted by
|
||||
`COMM`, since `pgrep -f` self-matches and gave a false `1` first), 0 scratch guests, no quiesce marker.
|
||||
|
||||
### The headline — `age_state=unknown` on real hardware, first ever
|
||||
|
||||
```json
|
||||
{"vmid":9201,"due":true,
|
||||
"reason":"backup storage unreadable and no in-memory record — age UNKNOWN, treating as due",
|
||||
"target":"felhom-pbs","age_state":"unknown"}
|
||||
```
|
||||
|
||||
Identical on both boxes. The transition is timestamped on demo-felhom:
|
||||
|
||||
```
|
||||
18:35:30 felhom-pbs/content 200 ← before power-off
|
||||
18:39:26 felhom-pbs/content 500 ← after
|
||||
18:39:11 local/content 200 ← local tier, same window, unaffected
|
||||
```
|
||||
|
||||
Agent journal, both boxes: `could not read the backup storage for the due-check … target=felhom-pbs`
|
||||
— the degrade path genuinely executed. **Positive observables throughout**, per standing rule 3: an
|
||||
empty quiesce log alone would have been equally consistent with a dead loop.
|
||||
|
||||
### The behaviour it gates
|
||||
|
||||
demo-felhom's `local` tier was **genuinely due** (25.8 h) for the whole window, so the due set was
|
||||
`[local(known), felhom-pbs(unknown)]` → `oldestAge` nil → `valveLicensed` false → **defer**. This is
|
||||
the 09:02 incident's exact condition replayed with the fix in place.
|
||||
|
||||
| | demo-felhom | demo-hp |
|
||||
|---|---|---|
|
||||
| App containers running | **10**, unchanged | **3**, unchanged |
|
||||
| Quiesce cycles | **0** | **0** |
|
||||
| Quiesce marker | absent | absent |
|
||||
| vzdump attempted | none since 07:13 | none since 09:37 |
|
||||
|
||||
**Not one app stack was stopped.** Per-tier isolation demonstrated on the same box in the same
|
||||
minute: `local` → 200 with a real age, `felhom-pbs` → 500 → unknown.
|
||||
|
||||
### Item 4 — conditions did not arise, and that is confirmed, not assumed
|
||||
|
||||
`felhom-pbs` was not due on either box (28 h / 7 h against a 168 h cadence), so no backup ran, nothing
|
||||
failed, **the R-88 breaker did not arm**, and **no `whole_guest_backup_failed` travelled**. I did not
|
||||
force one. Confirmed positively: the newest hub event is `16:10:33`, *before* the window opened at
|
||||
16:24, and 0 events exist in the window.
|
||||
|
||||
## Part 2.2 — post-boot
|
||||
|
||||
| Check | Result |
|
||||
|---|---|
|
||||
| felhom-agent | v0.96.0 → **v0.104.0** |
|
||||
| felhom-controller | v0.173.0 → **v0.175.0** |
|
||||
| felhom.eu hub | v0.74.0 → **v0.77.0** |
|
||||
| host-install | 1.19.0 → **1.20.0** |
|
||||
| Mount | `/mnt/pbs-datastore ext4 rw,relatime,discard` — **relatime present, `noatime` ABSENT** ✅ |
|
||||
| Swap | `/swapfile 4G` back — **survived its first reboot** (it was added and verified without one) ✅ |
|
||||
| PBS services | `proxmox-backup` + `proxmox-backup-proxy` both active ✅ |
|
||||
| Datastore | `felhom-offsite → /mnt/pbs-datastore`, online ✅ |
|
||||
| Snapshots | demo-felhom **2**, demo-hp **3** — **exact match**, same timestamps ✅ |
|
||||
| Schedules | `gc-schedule sun 04:30`, `verify-new 1`, 2 prune jobs ✅ |
|
||||
| Filesystem | `EXT4-fs (sda): recovery complete` — journal replayed after the unclean power-off, then mounted r/w; **0** I/O or EXT4 errors ✅ |
|
||||
|
||||
All live on demo-felhom and demo-hp.
|
||||
|
||||
---
|
||||
|
||||
## 1. The arc, in one line each
|
||||
|
||||
| Item | What it was |
|
||||
|---|---|
|
||||
| **R-80** | Diagnose `expected_backup_missed` firing on three boxes. **The premise was wrong on both counts** — it fired ONCE, not nightly, and no real external customer was notified |
|
||||
| **R-81** | Fix the CLASS behind it: absence of a signal treated as evidence of failure. Third instance |
|
||||
| **R-82** | The backup target split — "local daily + PBS weekly" was **not expressible at all**, which is why the DR tier was `applied` and empty |
|
||||
| **R-84** | An agent restart no longer triggers a redundant backup |
|
||||
| **R-85** | The DR tier is restore-tested **unattended**, and its failure is **heard** |
|
||||
|
||||
---
|
||||
|
||||
## 2. R-80 — the diagnosis, and what it actually found
|
||||
|
||||
The alarm fired at 2026-07-26 03:00 UTC on demo-felhom, demo-hp and drill-r50. The brief described it
|
||||
as nightly, on three customers, one reaching a customer channel with a 7.3-day staleness claim.
|
||||
|
||||
**It fired exactly once.** The check ran and was correctly silent on every prior night. The one
|
||||
customer-channel mail went to the operator's own mailbox; `peti-felhom` — the only real external
|
||||
customer — did not fire at all. And the 7.3 days was the age of the **PBS** snapshot, reached only as
|
||||
a fallback: the local tier had run on 07-24, 07-25 and 07-26.
|
||||
|
||||
**Root cause:** the agent's backup store is in-memory (`"lost on restart; the cadence re-populates"`).
|
||||
The R-50 fleet restart at 12:44 UTC emptied `backups[]`; the next backup landed at 07:03 the following
|
||||
morning; the 03:00 check fell in that ~18 h blind window and read empty as *no backup exists*.
|
||||
|
||||
**One real finding stood:** the PBS/offsite tier had **no schedule at all**. demo-felhom held one
|
||||
snapshot from a healing artifact; demo-hp held **zero, ever**, while reporting `applied` since 07-21.
|
||||
|
||||
---
|
||||
|
||||
## 3. R-81 — fixing the class, not the instance
|
||||
|
||||
`assessBackupFreshness` collapsed *absence of records* into *failure*. It now returns
|
||||
**OK / UNKNOWN / MISSED**: absence is UNKNOWN until it outlives a window anchored at first contact.
|
||||
|
||||
The anchor was **free** — a Phase-0 probe found the hub already retains 90 days of host-reports, so
|
||||
`GetHostReportsSince` + `newestBackupEvidence` answer *"when did I last SEE evidence of a backup?"*
|
||||
rather than *"what does the latest report say?"*. No agent change, no new state.
|
||||
|
||||
**Not silence.** A genuinely dead box must still alarm — that is the half the naive fix breaks, and
|
||||
`TestBackupFreshness_NoEvidenceBeyondAnchor_Alarms` is what makes the suppression safe.
|
||||
|
||||
The invariant is now written at the head of the function naming all three instances (v0.12.0,
|
||||
v0.73.0, R-81), pinned by a boundary test whose name says what it protects.
|
||||
|
||||
---
|
||||
|
||||
## 4. R-82 — the target split
|
||||
|
||||
`BackupTarget()` returned ONE string and `BackupCadence()` ONE 24 h window.
|
||||
|
||||
**Phase 0 gates:** weekly CONFIRMED (the only 7-day-exposed state is the non-SMB half of
|
||||
`settings.json`; `encryption.key` and the offbox credentials are **stable files unchanged since first
|
||||
boot**, so a week-old copy is byte-identical). The `pvesm status` 0/0/0 anomaly resolved as a
|
||||
namespace-scoped-token reporting artifact. Capacity raised a **STOP**, which the operator ruled past.
|
||||
|
||||
**Measured, not bracketed:** the second weekly snapshot cost **+2.7 GB** against 14.46 GB logical
|
||||
(~81 % dedup). Weekly top-ups are cheap; **first** snapshots are not. Per-tenant encryption means
|
||||
**no cross-customer dedup**, so the 80 % warn arrives at roughly the first additional customer.
|
||||
|
||||
**Shipped:** per-tier cadence/retention/wait-bound (agent); **one quiesce window for both tiers**
|
||||
(controller — two cycles would mean two app outages for one night's work); per-tier thresholds
|
||||
(hub, host 26 h / offsite 8 d); fresh-install default (installer).
|
||||
|
||||
### Four defects found by RUNNING it, not reviewing it
|
||||
|
||||
1. **v0.98.0** — a 41-minute backup recorded `success:false` at 30 minutes **while still running**,
|
||||
then completed `TASK OK`. Worse than "didn't happen": the tier stays due and the retry hits the
|
||||
guest lock.
|
||||
2. **v0.100.0** — the restore tier read from the configured target, not the archive. **A silent
|
||||
regression of the S4.1 fix** — the mechanism was never removed; its *input* changed when
|
||||
`local_backup_target` was retargeted to `local`.
|
||||
3. **v0.101.0** — a leaked scratch kept `onboot: 1`; a host reboot would have started a clone of the
|
||||
live guest.
|
||||
4. **v0.102.0** — a tier fired at a storage that does not exist yet.
|
||||
|
||||
---
|
||||
|
||||
## 5. R-84 — ground truth instead of memory
|
||||
|
||||
Three redundant local backups ran in one afternoon of deploys, because a restart empties the store.
|
||||
On the offsite tier that is a wasted multi-hour upload after **every** agent deploy.
|
||||
|
||||
Fixed by **asking the storage**, not persisting the record: a pruned archive correctly stops counting,
|
||||
where a persisted record would keep claiming a backup that no longer exists. Proven live on both
|
||||
boxes with the store cold.
|
||||
|
||||
---
|
||||
|
||||
## 6. R-85 — unattended, and audible
|
||||
|
||||
Three defects, each verified at source: the scheduler only ever saw `BackupTarget()`; the spec was
|
||||
**frozen at daemon start** (an immediately-invoked function — also a latent staleness bug); and a
|
||||
failed restore-test was a `[WARN]` line with **no event, no notification, no gauge** — true for the
|
||||
local tier that *was* being tested.
|
||||
|
||||
**Ruling (operator): oldest-first.** Never-proven sorts first, which is where the offsite tier starts.
|
||||
Rotation credit **only on success**, or a permanently failing tier looks freshly proven and stops
|
||||
being retried. State persisted — unlike R-84 there is no ground truth, because a restore-test destroys
|
||||
its scratch and leaves no artifact.
|
||||
|
||||
**`backup.InFlight`** — a host-wide one-heavy-operation gate. Not a lock concern (the scratch VMID
|
||||
never touches the live guest's vzdump lock) but a **LINK** one: an offsite restore PULLS multi-GB over
|
||||
the tunnel a backup PUSHES one. Callers **defer**; they never cancel.
|
||||
|
||||
**Two hub signals, never merged:** `restore_test_failed` (broken now) and `restore_test_stale`
|
||||
(*unverified*, not known-broken). Anchored on R-81, operator-tier only.
|
||||
|
||||
---
|
||||
|
||||
## 7. Live evidence
|
||||
|
||||
**The restore round-trip PASSED** (demo-hp, manual):
|
||||
```
|
||||
source_tier: pbs pass: true verified: boot+running mount_parity: ok 4m5s, clean teardown
|
||||
```
|
||||
`mount_parity` is the non-hollow half — a boot-only verify cannot see a missing data volume.
|
||||
|
||||
**The multi-tier quiesce ran** through the real UI endpoint (authed + CSRF):
|
||||
exactly **ONE stop/start pair with BOTH backups inside it**, app quiesced through the non-last tier,
|
||||
early resume on the last tier's snapshot. **Downtime 1m27s for both tiers.**
|
||||
|
||||
**Rotation proven unattended** (demo-hp):
|
||||
```
|
||||
tier selected (oldest-proven first) target=felhom-pbs ← never-proven sorted first
|
||||
scheduled restore-test passed duration_s=194.8
|
||||
tier selected (oldest-proven first) target=local ← rotated
|
||||
```
|
||||
|
||||
**The signal fired on its first sweep — on real faults:**
|
||||
```
|
||||
[ERROR] drill-r50 Restore-test FAILED on the local tier … HTTP 403 missing privilege VM.Backup
|
||||
[WARN] demo-felhom pbs tier: NEVER restore-proven in 205h (limit 168h) — unverified, not known-broken
|
||||
[INFO] demo-hp pbs tier: watching 133h of a 168h grace — newborn, not a fault
|
||||
```
|
||||
The first two are genuine, previously-invisible failures. All notifications went to the **operator**
|
||||
channel; the DB confirms no customer routing.
|
||||
|
||||
**demo-hp's first ever offsite backup landed** — 4.25 GB into a verifiably empty namespace.
|
||||
|
||||
---
|
||||
|
||||
## 8. Mistakes I made, and what they cost
|
||||
|
||||
Recorded because the pattern matters more than any one of them.
|
||||
|
||||
1. **I claimed the restore-test would break the control plane** by booting a network-conflicting
|
||||
clone. **Wrong** — it link-downs every NIC before boot, and that is unit-tested. I read a config
|
||||
artifact and inferred behaviour without reading the code that consumes it, *then escalated before
|
||||
finishing the check*. I also disabled a safety mechanism on that basis; it is re-enabled.
|
||||
2. **I pushed one commit red** — read `packages ok: 28` and missed `rc=1` in the same command. Five
|
||||
of my own tests were failing.
|
||||
3. **I planted a time bomb in Slice C** — a test hard-coded the incident timestamp
|
||||
`2026-07-18T18:31:06Z` while comparing against the real clock. It passed all day and began failing
|
||||
at exactly 18:31 UTC, 8 days later. A test that passes at commit time and fails hours later is
|
||||
worse than one that fails immediately.
|
||||
4. **I left `REPORT.md` claiming "not deployed"** 26 minutes before deploying, and did not update it.
|
||||
5. **Two bad observables** while verifying the controller: read a UTC timestamp as host time, then
|
||||
checked for log lines the agent does not emit at INFO. Both produced confident wrong readings.
|
||||
6. **I told the operator blocking would not silence the new alerts.** Wrong — blocked customers are
|
||||
excluded by `GetActiveCustomerIDs` already.
|
||||
7. **My own spec's §5.3 was wrong** — it said to force a failure with `--selftest`, but the selftest
|
||||
runs in a separate process and never reaches a host-report.
|
||||
|
||||
The recurring shape: **inferring behaviour from an artifact instead of reading the code path that
|
||||
consumes it**, and **reading a result without reading its exit code**. The host=CEST /
|
||||
component=UTC mismatch caught me twice in one session.
|
||||
|
||||
---
|
||||
|
||||
## 9. State at close
|
||||
|
||||
| | |
|
||||
|---|---|
|
||||
| Backups | local daily + offsite weekly, both boxes |
|
||||
| Offsite retention | 2 weeks (`keep_last=2`) |
|
||||
| Restore-test | **rotating both tiers, unattended**; interim cadence 3.5 d → each tier ~weekly |
|
||||
| Signals | failure + staleness, operator-only |
|
||||
| drill-r50 | VM 300 **stopped**, `onboot=0`. Operator will block the customer |
|
||||
|
||||
### demo-felhom's offsite restore-test — PASSED, and my estimate was wrong
|
||||
### The unplanned finding: the volume changed device name
|
||||
|
||||
```
|
||||
tier selected (oldest-proven first) target=felhom-pbs archive=…2026-07-26T12:21:48Z (14.46 GB)
|
||||
scheduled restore-test passed duration_s=635.07 ← 10m35s
|
||||
tier selected (oldest-proven first) target=local ← rotated
|
||||
before: volume=/dev/sdb root=/dev/sda1
|
||||
after: volume=/dev/sda root=/dev/sdb1
|
||||
```
|
||||
|
||||
**Rotation is now proven unattended on BOTH boxes**, and the persisted state confirms it:
|
||||
`{"felhom-pbs": "2026-07-27T06:14:42Z"}` — credit recorded, so the next cycle picks the other tier.
|
||||
The kernel enumerated the disks in the opposite order across the reboot. The mount survived only
|
||||
because fstab uses `/dev/disk/by-id/scsi-0HC_Volume_106469259`. **A `/dev/sdb` entry would have failed
|
||||
to mount — or mounted the root disk's device node.** That choice was load-bearing and had never been
|
||||
tested; this reboot tested it.
|
||||
|
||||
**Correction worth carrying forward: I estimated ~2 hours for this restore and it took 10m35s.**
|
||||
I derived the estimate from a download rate measured during the *failed* attempt, which was running
|
||||
under contention; the real link does ~1.4 GB/min. I then used that wrong figure to raise a design
|
||||
concern — that the heavy-operation gate would block backups for hours on this box. **At 10 minutes
|
||||
that concern largely evaporates**, and the same correction applies to the SPEC's closing risk note.
|
||||
An estimate extrapolated from a degraded measurement is not a measurement.
|
||||
### Recovery
|
||||
|
||||
## 10. NOT done — explicitly
|
||||
Both boxes returned to `age_state=known` on both tiers within ~60 s of boot; `felhom-pbs` on
|
||||
demo-felhom back to `due=false, within cadence window, age_seconds=102102`. No breaker was armed, so
|
||||
none needed clearing; no failure event fired, so no recovery event was expected — and none appeared.
|
||||
|
||||
1. **The restic (app-data offsite) tier is NEVER restore-tested** → **R-87**. R-85 covers whole-guest
|
||||
vzdump tiers only. This is arguably the tier that matters most: the only one that survives losing
|
||||
the box **and** carries the customer's app data (the whole-guest snapshot excludes the
|
||||
bind-mounted drives). It is exactly the state PBS was in yesterday.
|
||||
2. **Restore-tests are interval-scheduled, not backup-aligned** → **R-86** (operator ruling
|
||||
2026-07-27: ~1 day after that tier's own backup).
|
||||
3. **Rotation observed on demo-hp only**, and under a compressed cadence. It proves the rotation
|
||||
logic, not the production interval.
|
||||
4. **The hub infers "PBS ⇒ weekly" from storage TYPE**, not a reported cadence. No box is in the
|
||||
wrong shape today.
|
||||
5. **The installer-default fleet flip** awaits a full weekly cycle.
|
||||
6. **`07-backup-architecture.md` is NOT ratified** — brought current with an honest staleness header;
|
||||
ratification is Viktor's review of the §10 list.
|
||||
7. **The customer-facing Hungarian copy still overstates scope** — unchanged since R-80 flagged it.
|
||||
8. **Capacity:** the datastore still needs growing before the first real customer.
|
||||
## Part 3 — CX33
|
||||
|
||||
---
|
||||
**Not available even with the server powered off**, so the powered-on theory is settled: it is the
|
||||
Cost-Optimized line's "Limited availability", not the power state. No rescale happened. R-90 stays
|
||||
`BLOCKED`/`WATCHING` with the 4 GiB swap as the interim — now a *proven* interim, since it survived a
|
||||
reboot. Escape hatch if 8 GB becomes urgent: the **Regular Performance (CPX)** / **General Purpose
|
||||
(CCX)** lines carry no availability warning, at higher cost. Operator's call.
|
||||
|
||||
## 11. POST-SESSION — live state at hand-off (2026-07-27 ~07:10 UTC)
|
||||
## Comes off the never-live-validated list
|
||||
|
||||
Recorded after §1–§10 were written. Two facts, both still true at hand-off.
|
||||
- **`age_state=unknown` observed on real hardware** — the path R-88 Part 2 exists for.
|
||||
- **The window gate refusing an unknown-driven valve, with a genuinely due tier present** — zero app
|
||||
stacks stopped.
|
||||
- **Per-tier isolation under a real offsite outage.**
|
||||
- **The by-id mount surviving a reboot** (and surviving a device rename, which was not anticipated).
|
||||
- **The 4 GiB swap surviving a reboot.**
|
||||
- **Datastore integrity across an unclean power-off** — journal replay, exact snapshot match.
|
||||
|
||||
### 11.1 The offsite PBS outage — ~15 minutes, OOM-driven, RESOLVED
|
||||
## Honestly cannot come off it
|
||||
|
||||
**Root cause established, on the box.** `felhom-hetzner` (167.233.158.164) did **not** reboot
|
||||
(`up 18 days`). At **06:58:12 UTC a global OOM** fired: `proxmox-backup-proxy` had grown to a
|
||||
**3.2 GB peak on a 3.8 GB box** (systemd's own accounting at the later restart:
|
||||
`Consumed 42.395s CPU time, 3.2G memory peak`) and a concurrent root `rsync` at **1.9 GB RSS** tipped
|
||||
it over. The kernel killed the rsync. PBS stopped serving from ~07:00 to **07:17:59 UTC**, then
|
||||
recovered on its own — evidenced by the PVE API access log for the agent's ground-truth reads:
|
||||
`500` at 09:02/09:07/09:12 CEST, `200` from 09:17:59 CEST onward, uninterrupted since. A **separate**
|
||||
deliberate proxy restart at 07:52:52 UTC cleared unrelated `read fs info on "/srv/pbs-scratch" failed
|
||||
- ENOENT` spam; it was not the recovery.
|
||||
|
||||
**This session's restore-test is the most likely driver of the proxy's 3.2 GB peak** — it read
|
||||
14.46 GB off that datastore 06:44–06:58 UTC, finishing 9 seconds before the OOM. Not provable from
|
||||
what is on the box, but the timing and the memory figure both point at it, and the rsync was the
|
||||
*victim* rather than the cause. **This bears directly on R-86:** restore-testing a tier weekly means
|
||||
putting a multi-GB read on a 4 GB offsite box *on a schedule*. Either the box needs more RAM before
|
||||
that lands, or the restore-test needs to not run concurrently with whatever else touches that
|
||||
datastore. See also the existing note on rsync over a PBS chunk store.
|
||||
|
||||
**Access correction worth carrying:** root SSH to that box works **from DooPlex to the public IP**
|
||||
(`root@167.233.158.164`), and **not** from felhom-pve to the tunnel IP `10.77.0.1`. I concluded "no
|
||||
access exists" from the second failing and stopped diagnosing — the project memory recorded the
|
||||
working path and I did not check it until later. The whole root cause above came from finally trying
|
||||
the documented route.
|
||||
|
||||
### 11.2 R-88 — an unreachable target takes the customer's apps down on a loop
|
||||
|
||||
The agent restart that applied the reverted 3.5-day cadence exposed **R-88**: an unreachable target
|
||||
reads as *no backup exists*, so the offsite tier is perpetually "due". Three full quiesce cycles ran
|
||||
(07:02:57, 07:07:58, 07:12:57 UTC), each stopping and restarting all four app stacks for a backup
|
||||
that could not succeed — ~19 s of app downtime per cycle, ~50 s per full cycle.
|
||||
|
||||
**It stopped after three only because PBS recovered.** There is no limiter: `internal/quiesce` has no
|
||||
failure counter, backoff, breaker or attempt budget, and the driver is a plain 5-minute ticker
|
||||
(`quiesce.go:149`). Had the outage lasted, the loop would have continued indefinitely.
|
||||
|
||||
**The amplifier found while verifying that:** the agent answers `AgeSecs: nil`, and
|
||||
`scheduledRunAllowed` (`quiesce.go:466-480`) returns `true` whenever the age is nil — *"never
|
||||
withhold the first one"*. So the same missing value that makes every poll due **also bypasses the
|
||||
time-of-day gate**. The gate was `[04:30, 08:30)`; the cycles ran 09:02–09:12 Budapest, outside it.
|
||||
A safety valve written for a genuine first-ever backup is being tripped by a failed storage read.
|
||||
|
||||
**Operator ruling 2026-07-27: leave it running** (given while PBS was still down) — demo box,
|
||||
contained impact, self-heals, and leaving it keeps the fault visible rather than masked. It has since
|
||||
self-resolved; no action is outstanding on the box.
|
||||
|
||||
**I got the severity wrong twice before measuring it.** First as "one spurious event per restart"
|
||||
(it was a repeating loop), then as "three tries, so something limits it" (nothing does — the
|
||||
condition ended). Both readings were asserted from the mechanism I had reasoned about rather than
|
||||
from what the box and the code actually showed; the second was only caught by reading
|
||||
`internal/quiesce` instead of inferring a breaker from three log lines. Same shape as the ~2-hour
|
||||
estimate in §9.
|
||||
|
||||
### 11.3 Verified clean at hand-off
|
||||
|
||||
Agent `felhom-agent 0.104.0` active on demo-felhom, `restore-test scheduler starting cadence=84h0m0s`,
|
||||
both tiers armed (`local` 24h / `felhom-pbs` 168h). The scratch guest leaked by the mid-test restart
|
||||
was destroyed — **990000 band empty, zero leftover LVs**. `onboot: 0` held on that leaked scratch,
|
||||
which is the **v0.101.0 fix working in exactly the scenario it was written for**.
|
||||
|
||||
---
|
||||
|
||||
## 11. Observations
|
||||
|
||||
- **drill-r50's 403** (`missing privilege VM.Backup at /vms/9100`) is real and was invisible. The box
|
||||
is being retired, so it needs a decision — fix or accept — not silence.
|
||||
- **A blocked customer is hidden from the Dashboard and from every checker**, and it is reversible
|
||||
(`configs.go` sets status back to `active`, with a UI affordance). Blocking is a blunt instrument
|
||||
though: it silences *everything*, which is why the operator is building per-alert silencing.
|
||||
- **The PVE UI will permanently show `felhom-pbs` at 0 %** (namespace-scoped token). Read fill from
|
||||
the hub's PBS-DR gauge.
|
||||
- **demo-felhom's guest grew 9.74 → 14.46 GB logical in eight days.** Probably one-off from app
|
||||
testing, but if it is a rate the capacity sizing changes quickly.
|
||||
- **Three of the five items in this arc were the same bug class** — absence of a signal read as
|
||||
evidence, or a correct mechanism whose input changed underneath it. Both are now written into the
|
||||
code as invariants rather than left as lore.
|
||||
- **The R-88 breaker has still never armed on real hardware.** No backup was due, so none failed.
|
||||
- **`whole_guest_backup_failed` has never travelled from a REAL failure** — only from the induced
|
||||
POST on 2026-07-27 15:04:57. The quiesce→notify link remains unit-proven.
|
||||
- **R-97b's app-alarm suppression has never fired live** — it needs a real quiesce cycle.
|
||||
- **`age_state=absent` has never been observed live** — it needs a genuinely fresh tier.
|
||||
- **The legacy-agent path (Scenario C) is now unobservable on this fleet** — both agents are v0.105.0.
|
||||
- **The first in-window scheduled backup** lands 2026-07-28 at the earliest.
|
||||
|
||||
@@ -9,14 +9,14 @@ State: `BLOCKED` · `READY` · `WAITING-ON-OPERATOR` · `WATCHING`. Every row ha
|
||||
| ID | What | State | Blocked on | Next action | Owner |
|
||||
|---|---|---|---|---|---|
|
||||
| **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*~~ | **SHIPPED** (agent v0.105.0 + controller v0.178.0, 2026-07-27) | — | `age_state` known/absent/unknown; empty = legacy. MinAgent 0.105.0, met on both boxes | — |
|
||||
| **R-88b** | ~~`/backup/due` cannot say *unknown*~~ | **SHIPPED + PROVEN-LIVE** (agent v0.105.0 + controller v0.178.0, 2026-07-27) | — | `age_state=unknown` captured on real hardware during a deliberate ep0 outage; controller deferred, **zero app stacks stopped** | — |
|
||||
| **R-95** | restic offsite credential **can delete** (`readonly=False`, `forget --prune` runs from the box); SFTP cannot express append-only | **READY #1** | — | Root exposure still open. Mitigation now ARMED — 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 #2** | — | 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 #3** | R-90 (ep0 headroom) informs cadence | Trigger a tier ~24 h after **its own** newest archive | CC |
|
||||
| **R-87** | The restic tier is never restore-tested | **READY #4** | — | Design a controller-side test (no scratch-guest analogue transfers) | 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 added 2026-07-27** (persistent, verified without reboot); 3.8 GB RAM unchanged | **BLOCKED** (interim done) | Hetzner CX33 availability | Rescale when available; swap now covers Sunday's first GC | operator |
|
||||
| **R-90** | ep0 RAM headroom — 4 GiB swap **survived its first reboot** 2026-07-27; 3.8 GB RAM unchanged | **BLOCKED** (interim proven) | Hetzner CX33 availability — **confirmed unavailable even powered OFF**, so it is the Cost-Optimized "Limited availability", not the power state | Re-check CX33; escape hatch if urgent = CPX/CCX lines (no availability warning, higher cost) | operator |
|
||||
| **R-91** | Old 13 GB datastore copy at `/srv/pbs-felhom` on ep0's root disk | WATCHING | demo-felhom's first **post-migration** PBS backup | Delete once it lands; fix `CONTEXT.md:1018` same commit | CC |
|
||||
| — | First-ever **GC** on `felhom-offsite` (armed today 13:11 UTC, never run) | WATCHING | schedule | **Sun 2026-08-02 04:30 UTC** — confirm it completes | CC |
|
||||
| — | demo-felhom's next weekly PBS backup (newest is 2026-07-26) | WATCHING | schedule | ~2026-08-02; also releases R-91 | CC |
|
||||
|
||||
Reference in New Issue
Block a user