From 0887fd676d608e7c103fa13b3e87536ad2481811 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Mon, 3 Aug 2026 13:59:42 +0200 Subject: [PATCH] =?UTF-8?q?REPORT:=20R-182=20=E2=80=94=20the=20run=20diges?= =?UTF-8?q?t,=20the=20live=20proof,=20and=20the=20red-proof=20that=20did?= =?UTF-8?q?=20not=20fail=20first=20time?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- REPORT.md | 170 ++++++++++++++++++++++-------------------------------- 1 file changed, 68 insertions(+), 102 deletions(-) diff --git a/REPORT.md b/REPORT.md index 38a3539..a6a950f 100644 --- a/REPORT.md +++ b/REPORT.md @@ -1,131 +1,97 @@ -# REPORT — R-181: the reserve guards the write that fills the disk, and its promise is true +# REPORT — R-182: one operator email per backup run, and nothing dropped without a trace -**Date:** 2026-08-03 · **Repo:** `felhom-controller` · **v0.192.0 → v0.193.0 → v0.193.1** -**Commits on `main`:** `fef07c3` (v0.193.0), `6c43bf6` (v0.193.1) · **Baseline on arrival:** `4be6467b501b`, v0.192.0 (matched) +**Date:** 2026-08-03 · **Repo:** `felhom-controller` · **v0.193.1 → v0.194.0** · commit `88897a2` +**Baseline on arrival:** `db0d4b129d3b`, v0.193.1 — matched §1. ## The defect -B2's capture floor (v0.192.0, R-165) shipped as the deliberate replacement for the bulkhead the `mp1` -partition used to give, and it was consulted in **exactly one place** — `captureAllRecoveryUnits`, -which writes a manifest and three compose files: a few KB. The two legs that write the **bulk** into -the same `backups/primary/` tree — the database dump and the volume dump — ran **first** and -**unguarded**. +Nine per-app `recovery_unit_capture_failed` events reached the hub on 2026-08-03 and **two operator +emails went out**. The hub's operator cooldown key is `customerID:eventType(+tier)`, and that event +carries `app` but **no `tier`** — so the key held no app identifier. The first refused app took the +hour's slot and every other app's failure was discarded **before `LogNotification`**, leaving no row +on any channel. -Measured live on demo-hp 2026-08-03 06:40:03: opengist's volume dump wrote **2.0 GB with no check**, -free fell to 1.0 GB, and the floor then refused the cheap write it had already lost the argument to. +**The obvious fix was ruled against:** putting `app` in the key produces one email per failing app, +which on a full disk is a dozen. -**Second limb:** the refusal printed *"the previous unit is untouched and NOTHING was deleted"*. -*Nothing was deleted* held. *Untouched* was **measured false** — that app's tar had gone -182,272 B → 2,147,666,432 B under a `manifest.json` whose `created_at` and `checksums` had not moved. -Sixth entry in `CLAUDE.md`'s table of shipped guarantees the code did not provide. +## What ships -## The fix +`internal/backup/runsummary.go` — a per-run collector with exactly `admissionSet`'s lifetime, fed by +all three write legs, emitting `backup_run_failures` **once** at the end and **only when something +failed**. The per-app event stays and becomes the record. -**One admission verdict per app per run** (`internal/backup/admission.go`), taken before that app's -**first** write and consulted by all three legs. They write under one per-app root -(`appbackup.RecoveryUnitPath`), which is what makes one verdict able to cover them honestly. +- **A refusal is noted ONCE, inside `admitApp` where the verdict is taken** — not at the three legs + that consult it. R-181's contract is one verdict per app per run; noting per leg listed a single + refused app three times and produced *"2 of 1 apps failed"*. **Found by the digest's own test.** +- **Deliberate skips are excluded** — a disconnected or decommissioned drive has its own alert. +- **A manual run always reports:** a unique `run_id` the hub's cooldown cannot collapse. -- **Lazy, at the app's first write — not once at run start.** App A's dump can put app B under the - reserve; a run-start verdict reads a disk that no longer exists. -- **Never re-decided between an app's own legs** (that is the split being closed); **reset per run**. -- **Ahead of `DumpAppVolumesSafe`**, which stops the stack as its first act. **After** the volume-less - check, which has no write to gate. -- **Exactly one operator alert per refused app per run.** Leg order unchanged. -- **Size term:** *would this app's write cross the reserve?*, estimated from its previous `.sql` + - `.tar`. **No history → headroom-only**, or the first backup is the one that can never happen. +**A gap the spec did not anticipate, and its fix.** `recovery_unit_capture_failed` also fires from +`GetFullStatus`'s periodic sweep, outside any run. With it now record-only, those failures would have +been recorded and **never notified** — a new silence created while closing one. The sweep therefore +emits a digest too, deliberately with **no `run_id`**, so it stays under the ordinary hourly cooldown +exactly as before while the mail now lists every failing app instead of whichever was first. + +## §3's safety property — confirmed, not assumed + +`hub/internal/monitor/deadline.go:396` (`expected_backup_missed`) and `:417` +(`expected_dbdump_missed`) are raised by the **hub**, from `assessBackupFreshness(reportJSON,…)` and +`GetEventsByType` — i.e. from the box's report freshness and stored events, **independently of any +email the controller chooses to send**. A digest's silence therefore still means "the run finished +and found nothing wrong". This is what makes the whole design safe, and weakening that check +re-opens a silent-failure path. ## Files -`internal/backup/admission.go` (new), `admission_test.go` (new, 11 tests), `backup.go` (run scope + -DB-leg and volume-leg gates), `recovery_unit.go` (`floorVerdict` size-aware; capture leg via -`admitApp`), `capture_floor_test.go` (3 call sites), `controller/README.md`, `REUSE.md`, `CHANGELOG.md`. +`internal/backup/runsummary.go` (new) · `runsummary_test.go` (new) · `admission.go` · +`admission_test.go` · `backup.go` · `recovery_unit.go` · `internal/notify/notifier.go` · +`internal/web/handler_debug.go` · `internal/api/router.go` · `cmd/controller/main.go` · +`CHANGELOG.md` · `REUSE.md` -## Tests — `go build ./... && go vet ./... && go test ./...` → **28 packages ok, rc=0** +## Tests — `go build && go vet && go test ./...` → **28 packages ok, rc=0** -Read separately from any commit (standing rule 1). Refusal assertions are **sha256 tree fingerprints -before and after**, never log lines — the defect *is* a log line the tree contradicted. +7 new tests. `controller_gates.py` → all 8 OK. -The DB leg cannot run without Docker (`DiscoverDatabases` shells out), so its gate is pinned by an -**AST walk** of `backup.go` asserting `admitApp` precedes `DumpOne`; `strings.Contains` is -insufficient, a commented-out call still contains the string. +### Red-proofs -### Red-proofs — demonstrated failing, then restored +| # | Mutation | Result | +|---|---|---| +| A | **all four** `noteFailure` feeds removed (the pre-R-182 per-app-only path) | **RED** — Scenario A and the refresh-sweep test both fail; the digest is never emitted | +| I (1st attempt) | the `main.go` seam wiring commented out | **DID NOT FAIL — recorded as such.** The AST test walked the backup package and not `main.go`, so the seam could be disconnected with the suite green. **The test was fixed**, not the result recorded | +| I (re-run) | same mutation, against the fixed test | **RED** — and the string `SetRunSummaryNotify` is still present in the file, which is why this is an AST walk and not `strings.Contains` | -| Mutation | Result | -|---|---| -| **Both** dump-leg gates removed (= exactly v0.192.0) | Scenario A RED (*"the VOLUME leg ran for a refused app"*), and with the leg assertions temporarily non-fatal the **tree fingerprint changed** too. Also red: C, D, and the AST wiring test | -| The whole size term removed from `floorVerdict` | Scenario D RED — 0 alerts where 1 required | -| The reserve removed entirely | Scenario F **PASSED — recorded honestly.** It does not exercise the assertion: every app then writes, which overwrites and adds but **deletes nothing**, so a deletion-watching test correctly stays green | -| A prune injected into the refusal path | Scenario F RED — the mutation that actually proves it watches deletion | -| Floor moved above the warning band (90% / 6 GiB) | `TestFloorSitsBelowTheCriticalWarningBand` RED | - -`python3 controller/scripts/controller_gates.py` → all 8 gates OK. - -## Live validation — demo-hp guest 9201 (Tier 0) +## Live proof — demo-hp guest 9201 **Method:** endpoint-level — `POST /api/debug/backup/dbdump`, the exact endpoint the debug UI button calls, running the production `RunDBDumps`. No browser on DooPlex. -**Instrument re-proven first:** demo-hp's thin pool is 53.93 GiB, so a real fill of the 70 G volume -would exhaust it. A 5 GiB `fallocate` moved guest `df` 1.2G → 6.2G while `data_percent` held -**36.83 → 36.83** — zero blocks allocated. Re-checked at every fill step. +Filled for real with `fallocate` to **241 MB free / 100% used**; the thin pool held **30.78 → 30.78** +(instrument re-proven before use — demo-hp's pool is 53.93 GiB and a genuine fill would exhaust it). -**Headroom term, 08:59:46 (906 MB free / 99%):** `TREE_SHA=111d1760c18d3440f700634ab325f8b8` -**identical before and after** (opengist's tar still 182,272 B); **0** volume dumps; **no -`Stopping for safe volume dump` line at all** — evidence rather than absence, because that line -*is* present in the 08:58 baseline run; one alert per app, HTTP 200. Freed and re-run 09:01:33 → both -captured normally. +``` +[INFO] [backup] Run summary: 2 of 2 apps failed (manual run) — notifying the operator once +[INFO] Event pushed: backup_run_failures (error) — 2 of 2 apps failed to back up in this manual run: opengist, privatebin +``` -**Size term, 09:03:00, proven separately:** a real 2 GiB file in opengist's volume made its previous -tar **2,147,666,432 B** (the exact live figure); filesystem set to **91% used / 2.9 GB free — both -headroom terms deliberately clear**. opengist refused **`(size)`**; **privatebin was ADMITTED and -dumped normally**, so the term is per-app and not a global halt. +Both apps refused, **one** digest naming both. Against the previous behaviour: two refusals, one +email naming one app, one vanishing. Hub-side evidence is in `felhom.eu/REPORT.md`. -**One honest correction:** both apps' `StartedAt` did move, 26 s *after* the refusal — the **quiesce -loop** for the whole-guest PBS backup, which the fill had broken, not the app-data path. The -app-data claim rests on the absent `Stopping … for safe volume dump` line. - -## The `du` measurement — measured, then rejected - -**66 timed runs**, `docker run --rm -v :/v alpine du -sb /v`: **median ~355 ms/volume -(341–404 ms)** on volumes holding tens of KB — container start-up, not the walk. Rejected on two -further grounds: `docker run` needs the writable layer, so the instrument can fail under exactly the -pressure the reserve handles; and the previous-dump estimate measures the **artifact to be written** -rather than the live volume. The estimate stands. - -## v0.193.1 — found by the proof run itself - -The estimate was rendered fixed to two-decimal GiB, so opengist's real **178 KB** printed as -`estimated 0.00 GiB write` — which reads as *no estimate was available*, the opposite of what -happened. Shipped the same session because it is the same defect class. Arithmetic unchanged (still -GiB, the reserve's own unit); rendering moved to `humanizeBytes`. Re-verified live after redeploy: -`estimated 178.0 KB write`. - -## Deployed - -`gitea.dooplex.hu/admin/felhom-controller:0.193.1` on demo-hp guest 9201 — `Up (healthy)`. -Not deployed to demo-felhom (which carries the PBS-DR/offsite tier and was out of scope). - -## §3's correction — confirmed, not chased - -`restore_points.go:57-59` takes the manifest mtime then `newestArtifact` over `.sql` and `.tar`, so -the newest of the three wins. The restore point does **not** show a stale timestamp. +**Scenario E:** a second run in the same hour produced a second digest (11:50:45 and 11:51:28). +**Scenario B:** after freeing the space, the run completed with 2 volume dumps and **no** digest. ## Teardown -Fill removed; planted 2 GiB file removed; a final backup regenerated a correct 178 KB tar; -`pct fstrim 9201` returned 67.5 GiB and the pool settled at **29.43%**, below its 36.83% baseline; the -tree is byte-identical to the pre-test fingerprint. Guest helper scripts and the credential file -`shred`-ed. No `--no-verify` on either push; the pre-push hook ran and reported `gates OK` both times. +Fill file removed, guest helper scripts and the credential file `shred`-ed, `pct fstrim 9201` +returned 63.3 GiB, thin pool at **30.76**. Disk back to 1.9G used / 64G free. -## Observations — NOT acted on (filed in `felhom.eu/documentation/backlog/OPEN-ITEMS.md`) +## Observations — NOT acted on -1. **R-182 (filed).** `GetFullStatus` → `captureAllRecoveryUnits` runs with no admission scope, so a - refused app re-alerts on every status poll — measured: a second identical alert pair 13 s after the - run's. **Pre-existing in v0.192.0**; this change touched neither caller. -2. **A reserve refusal does not fail the run.** Both dump legs record `SKIP`, not `FAIL`, so - `lastDBDump.Success` stays true. Deliberate and consistent with v0.192.0, but "backup succeeded" - and "every app was backed up" are then not the same statement. -3. **`UnitSpace.UsedPercent` and `df` disagree** (94% vs 99%) — `df` accounts for ext4 reserved blocks - and the floor's figure does not. Harmless here, but the operator cannot reproduce the percent term - with `df`. +1. **Only two apps are deployed on the demo box**, so "several apps" was 2 of 2. That is exactly the + measured case being closed (two refusals → one email), but a five-app demonstration would be + stronger and needs a box with more apps. +2. **`FormatOperatorEmail` puts an emoji in every operator subject**, including this digest. Part 3 + asked for no emoji; the icon comes from the shared formatter, and changing it globally would alter + every other operator mail and its tests. Left alone deliberately — the digest's own copy has none. +3. **The digest's leg name for a refusal is `whole app (refused before any write)`** rather than a + specific leg, because the reserve refuses all three at once. Accurate, but longer than the other + leg names and it widens the column.