REPORT: R-181 — the reserve, the live proof, the du measurement and the teardown
gates / gates (push) Successful in 9s

This commit is contained in:
2026-08-03 11:37:33 +02:00
parent 6c43bf6156
commit db0d4b129d
+99 -203
View File
@@ -1,235 +1,131 @@
# REPORT — v0.191.0 / .1 / .2: warn before the wall comes down (R-167 · R-158 · R-174)
# REPORT — R-181: the reserve guards the write that fills the disk, and its promise is true
**Overwritten** per the standing rule; the prior contents (v0.190.0 / R-157 A · R-170 · R-171, same
day) have their durable record in `CHANGELOG.md`.
**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)
**Session:** 2026-08-02 · **Repos:** `felhom-controller` v0.190.0 → **v0.191.2**, `felhom.eu` hub
v0.88.0 → **v0.89.0** + docs. `felhom-agent` untouched (Part 3 read its golden-build script and
changed nothing in it).
## 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/<app>` tree — the database dump and the volume dump — ran **first** and
**unguarded**.
## 1. Baselines — one drifted
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.
| Repo | §1 said | Found on arrival | Match? |
|---|---|---|---|
| `felhom-controller` | `95eb5c2c1af4`, v0.190.0 | `95eb5c2c1af4`, v0.190.0 | **yes** |
| `felhom.eu` | `d5774d318941`, hub v0.87.0 | **`8ef92a3f`, hub v0.88.0** | **NO** |
**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.
**hub v0.88.0 had already shipped** (R-172, the WAL fix) between the task being written and this
session. Target corrected to **hub v0.89.0**. Highest register ID in use was **R-173**, not R-171.
## The fix
## 2. One decision taken with the operator before any code was written
**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.
Reconnaissance found that **`disk_warning` / `disk_critical` were a complete customer pipeline with no
producer** — in the hub's `allowedEventTypes`, carrying Hungarian `customerMessages`, in
`settings.DefaultEnabledEvents`, with a UI checkbox (`event_disk_alerts`) — and `grep` across all four
repos found **zero emitters**. The only thing reacting to guest disk pressure was `healthcheck.go:338`,
folding it into a generic `health_degraded` at 90% for registered storage paths only.
- **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.
The task said to mint a new customer-facing type. Doing so would have put a near-duplicate beside an
inert pair — and §5's own reason for rejecting `backup_failed` (it is customer-enabled and carries
Hungarian copy) is the argument *for* reusing this one, because D-c routes the fill warning **to the
customer**. **Operator chose: wire the existing pair.** So only ONE new hub type was minted (the
operator one), and the sixth *built-but-never-wired* instance was closed rather than joined by a seventh.
## Files
## 3. Files changed and commits
`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`.
**6 modified, 4 added.** `controller/cmd/controller/main.go`,
`internal/backup/{appstop_marker,backup,recovery_unit}.go`, `internal/notify/notifier.go`,
`cmd/controller/appstop_wiring_test.go`, `CHANGELOG.md`, `REUSE.md` · **new:**
`internal/fillwatch/{fillwatch.go,fillwatch_test.go}`,
`internal/backup/{appstop_drivegate_test.go,recovery_unit_notify_test.go}`
## Tests — `go build ./... && go vet ./... && go test ./...` → **28 packages ok, rc=0**
| Commit on `main` | Subject |
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.
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 — demonstrated failing, then restored
| Mutation | Result |
|---|---|
| `cf48214` | v0.191.0 — warn before the wall comes down (R-167, R-158, R-174) |
| `5adae4d` | v0.191.1 — the fill check also runs at startup (R-167) |
| `9a3c485` | v0.191.2 — a quiet fill check now says so (R-167) |
| **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 |
## 4. Tests
`python3 controller/scripts/controller_gates.py` → all 8 gates OK.
**1157 → 1184 (+27).** Full suite green in both repos (`go build ./... && go vet ./... && go test
./...`); all **eight** controller gates and all **five** felhom.eu gates OK. Hub: 574 → **579**.
## Live validation — demo-hp guest 9201 (Tier 0)
### Red-proofs — each mutated, observed failing, restored
**Method:** endpoint-level — `POST /api/debug/backup/dbdump`, the exact endpoint the debug UI button
calls, running the production `RunDBDumps`. No browser on DooPlex.
| # | What was mutated | Result |
|---|---|---|
| A1 | the `errors.Is(err, ErrStartRefused)` branch removed from `Recover` | **4 tests FAIL** — refusals collapse into `Failed` and alarm |
| A2 | `SetStarter(gatedAppStopStarter{…})``SetStarter(stackMgr)` (the v0.189.0 wiring) | `TestMainWiresGatedAppStopStarter` **FAILS** |
| C | the `m.unitNotify(...)` call removed from the capture loop | **2 tests FAIL** — the seam-never-wired shape |
| E | **both** edge guards removed | **3 tests FAIL** — warns twice; the dead zone breaks |
| G | `recovery_unit_capture_failed` removed from `operatorOnlyEvents` | **2 tests FAIL**, one reading *"a customer was emailed the OPERATOR-ONLY …"* |
| H | clear thresholds edited into equality with warn | `TestThresholdsKeepTheirHysteresisGap` **FAILS** |
| J | `fillWatcher.SetNotify(` **commented out** (string still in the file) | `TestMainWiresTheFillWatcher` **FAILS** — proves AST, not substring |
**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.
**One red-proof was a FALSE GREEN on the first attempt, and it is reported rather than quietly
redone.** Red-proof E's first mutation removed only `if next == prev { continue }`; a second guard
(`next <= prev`) still caught the repeat, so every test passed and the "proof" proved nothing. Redone
removing both guards. This is exactly the trap `CLAUDE.md` records — a mutation or a `-run` filter
that yields a green and reads like a completed proof.
**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 <app> 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.
**One pre-existing test was TIGHTENED, not loosened.** `TestMainReportsTheInterruptedOperation`
asserted the guard was `if appStopRecovery != nil`. R-174 makes that insufficient — `Recover` now
returns non-nil for a refusal-only recovery — so the test now *requires* `Alarming()` in the condition.
**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.
## 5. Thresholds and cadence, with their justification
**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.
| | value | why |
|---|---|---|
| warn | used ≥ **85%** OR free < **5 GiB** | a percentage alone lies at both ends of this fleet's real size range: 85% of a 20 G `mp1` leaves 3 G — less than one DB-backed app's unit (~2× its data, §7.5) — while 85% of a 4 TB drive leaves 600 G |
| critical | used ≥ **95%** OR free < **2 GiB** | below 2 GiB a volume tar of almost any real app fails: "the next backup will not complete", not "it is getting tight" |
| clear | used ≤ **75%** AND free ≥ **7 GiB** | both must hold; the gap to warn is the hysteresis dead zone, so a filesystem on the line does not flap. Pinned with a real margin, not merely an inequality |
| cadence | **daily 03:30** + **once 90 s after startup** | a fill is slow-moving, so a shorter interval buys no earlier warning; 03:30 precedes the nightly app-data legs, so a customer about to lose a backup hears about it with a night's margin. The startup run exists because neither `Daily` nor `Every` fires on registration — §7 |
## The `du` measurement — measured, then rejected
**The live proof vindicated the two-term design:** the critical crossing fired on the **free-byte**
term (1.7 GB) while the disk was only **91%** used. A percentage-only rule would have missed it entirely.
**66 timed runs**, `docker run --rm -v <vol>:/v alpine du -sb /v`: **median ~355 ms/volume
(341404 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.
## 6. The exact Hungarian customer copy, for review as copy
## v0.193.1 — found by the proof run itself
**`disk_warning`** (severity `warning`) — as rendered live on 9201:
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`.
> A(z) „Rendszer- és mentési terület” tároló 85% foglalt — 4,7 GB szabad hely maradt. Kérjük,
> szabadíts fel helyet, mielőtt megtelik: törölj felesleges fájlokat, vagy csatlakoztass új
> meghajtót. Ha megtelik, a biztonsági mentések meghiúsulnak.
## Deployed
**`disk_critical`** (severity `critical`) — as rendered live on 9201:
`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).
> A(z) „Rendszer- és mentési terület” tároló kritikusan megtelt: 1,7 GB szabad hely maradt (91%
> foglalt). A biztonsági mentések és az alkalmazások írásai bármikor meghiúsulhatnak. Kérjük,
> mielőbb szabadíts fel helyet: törölj felesleges fájlokat, vagy csatlakoztass új meghajtót.
## §3's correction — confirmed, not chased
Decimal **comma** throughout (`4,7 GB`); the storage is named by its **label**, never its path; both
end in an action. No emoji (asserted by a test; `emoji_gate` passes).
`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.
## 7. Two defects found by the validation itself, both fixed and shipped
## Teardown
1. **v0.191.1 — the check was reachable only on its daily schedule.** Neither `sched.Daily` nor
`sched.Every` fires on registration; both wait for their first tick. A box that BOOTS already over
the line would have stayed silent for up to 24 h — the R-100 shape, and the same gap the hub's own
checkers avoid by leaving already-breached keys unseeded at init. Now also runs once 90 s after
startup; safe because the check is edge-triggered against persisted state, so an already-warned
filesystem stays silent.
2. **v0.191.2 — a quiet run was unreadable as evidence.** After the customer had been warned, a
restart produced **zero** `fillwatch` lines — equally consistent with "ran and chose silence" and
"never ran". For an edge-triggered check **the quiet run is the healthy steady state**, so that
ambiguity is permanent, not rare. `Check` now logs a per-run summary (`checked N filesystem(s), M
unreadable/skipped, K notification(s); bands: …`), counting unreadable separately so a silently
unreadable drive cannot read as "all fine".
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.
## 8. Live evidence — three flows, guest 9201 on `felhom-pve`
## Observations — NOT acted on (filed in `felhom.eu/documentation/backlog/OPEN-ITEMS.md`)
**Method: endpoint/log-level on real hardware**, exercising the production paths — browser automation
is not available on DooPlex. The hub's `notification_log` was read from a **WAL-aware** copy of
`/data/hub.db` (all three files — R-172's lesson); the copies were deleted afterwards.
**Flow 1 — the guard refuses, keeps the marker, does not alarm.** Both `hdd_1` mounts held unmounted
against the agent's ~60 s heal, per the documented method:
```
[WARN] [appstop] refusing to restart "calibre-web" after an interrupted operation:
drive /mnt/felhom-drives/hdd_1 is not a live mountpoint
[WARN] [appstop] crash recovery: NOT restarting calibre-web — start refused by a deliberate
holder: … the marker is KEPT and the holder owns the restart
[WARN] [appstop] crash recovery: 1 app(s) were deliberately NOT restarted (drive absent) —
KEEPING the marker; this is the gate working, not a fault: [calibre-web]
[WARN] [appstop] …HELD… — not alarming: … restarted=[] held_by_drive=[calibre-web]
```
Marker retained **byte-identical**; `docker ps -a --filter name=calibre-web`**0**; no
`backup_failed` event. **Scenario B, on a later boot with the drive live:** `restarted calibre-web
after the interrupted an app-data backup (volume dump)` and the marker was **cleared**.
**Flow 2 — the operator event arrives; the customer is refused.** Two real capture failures:
```
Event pushed: recovery_unit_capture_failed (error) — Recovery unit capture FAILED for "calibre-web"
… /mnt/felhom-drives/hdd_1: 24.5/93.9 GB used (26%), 64.6 GB free. Error: … permission denied
```
Hub `notification_log` — the positive observable:
```
customer | recovery_unit_capture_failed | skipped | operator_only
operator | recovery_unit_capture_failed | sent |
```
**Flow 3 — the customer is warned, once, in Hungarian.** `/mnt/sys_drive` filled with `fallocate`:
| run | state | fired | log |
|---|---|---|---|
| 1 | 90% / 4.7 GB | `disk_warning` | `ok → warning … notifying the customer` |
| 2 | unchanged | **nothing** | (edge trigger held) |
| 3 | 91% / 1.7 GB | `disk_critical` | `warning → critical …` |
| 4 | file removed | **nothing** | `critical → ok … cleared silently, re-armed`; state emptied |
Hub: `customer | disk_warning | sent` and `customer | disk_critical | sent`, Hungarian rendered.
**Exactly two events across four runs.** Run 2's silence is meaningful **only because run 3 proves the
startup check executes every boot** — needing that inference is what motivated v0.191.2.
## 9. Deployed versions
```
$ ssh felhom-pve "pct exec 9201 -- docker ps --filter name=felhom-controller …"
gitea.dooplex.hu/admin/felhom-controller:0.191.2 | Up (healthy)
```
Hub: ArgoCD app `felhom` **Synced / Healthy** after a deliberate hard-refresh + sync (never
`kubectl set image`); `deploy/hub` rolled out; image `gitea.dooplex.hu/admin/felhom-hub:0.89.0`;
startup log clean.
## 10. Teardown
`R167-FILLTEST.bin` deleted (`/mnt/sys_drive` back to 2.0 G used / 45 G free); the app-stop marker
cleared by a successful recovery; `/root/hold-unmount.sh` + `/tmp/hold.log` removed from `felhom-pve`;
the secret-bearing local `hub.db*` copies deleted. **All 15 containers on 9201 healthy.**
**One self-inflicted incident, disclosed in full.** Restoring the drive by hand I ran
`mount --bind /mnt/hdd_1 /mnt/felhom-drives/hdd_1`, **omitting the `felhom-data` segment** the agent
uses (`felhom-agent/internal/localapi/intermediary.go:15`
`mount --bind /mnt/<name>/felhom-data /mnt/felhom-drives/<name>`). The guest then saw the drive root
instead of the namespace root, which an unprivileged guest cannot write to — producing real
`permission denied` capture failures. They served as flow 2's evidence, but **they were caused by me,
not found by me, and the report says so.** Separately, a manual `docker compose up -d` from a stack
dir started containers **without the controller-injected env** (there is no `.env` on disk — the
controller injects at exec time), which recreated `immich-server` with a blank DB password and left it
in a `28P01` auth-failure restart loop. Both were repaired through production paths: the bind
corrected, then the stacks brought back by the controller's own `StartStack` and boot reconciler
(`[bootrecon] … 1 app(s) recovered in 1 attempt(s): [immich]`). **Lesson, learned twice in one
session: on a box the agent manages, restore state by letting the agent and controller do it.**
## 11. Register rows
**Opened:** R-174 (closed same session), R-175, R-176, R-177 — each ID established free by
`grep -ro "R-17n\b" documentation/ *.md` → 0 hits. **Closed:** R-158 (by R-167 — *no second row was
filed for the same wire*), R-167, R-174. **Updated and still open:** R-165 (gains the spike's M1-M5
and the operator question).
## 12. CI and `--no-verify`
**`--no-verify` was NOT used.** Every push ran `.githooks/pre-push` (gates `--fast`) and it passed.
**CI checked by PULL, matching `head_sha` to each commit** — CI emails only on failure, so a green
that was never looked at is an assumption. All three commits green:
| Commit | Task id | Run # | Conclusion |
|---|---|---|---|
| `cf48214` (v0.191.0) | 31 | 11 | **success** |
| `5adae4d` (v0.191.1) | 34 | 12 | **success** |
| `9a3c485` (v0.191.2) | 35 | 13 | **success** |
The `felhom.eu` side (hub v0.89.0, the manifest bump and the docs) is in that repo's `REPORT.md` §6 —
also all green.
## 13. Observations — noticed, documented, NOT acted on
- **R-177** — no operator-triggerable "run this scheduler job now" path. It cost a controller restart
per observation here, and costs the same on a support call.
- **R-175** — `07-backup-architecture.md` §7.5 states one box's size bound as if it were the fleet's.
- **R-176** — two R-165 prerequisites are unmeasured (a pre-merge-archive restore-test; the in-place
migration rehearsal).
- **The drive gate's return branch failed to restart both apps** (`[WARN] [gate] restart calibre-web:
… exit code 1`) at a moment when a manual start succeeded seconds later. **Not filed as a row**: it
happened during my incorrect bind, so the likeliest cause is mine and the evidence is contaminated.
Worth a look if it recurs on a clean box.
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`.