chaos night round 9: what a lost hub report actually costs, measured
gates / gates (push) Successful in 21s

With the injector corrected, the hub really was unreachable. The controller
built its 23:08:42Z report, retried the push three times over 1m40.8s and
gave up at 23:10:23Z - 31 seconds before the link returned. Nothing queued,
which is correct: a report is a snapshot, not a fact.

The box passed. 26 containers throughout, every front door serving, both the
hub link and the host-agent link repaired unaided the moment the block lifted,
no alarm fired and none should have.

R-549 filed (P2): the staleness threshold (30 min) is exactly twice the report
cadence (15 min), so ONE failed push spends the entire budget. The measured gap
was 29m59s - one second inside the alarm. A healthy, self-repaired box came that
close to paging the operator.

Also recorded: the injected cut is broader than its name - it severed the
controller from its own host agent too, which a real ISP outage would not do.
The caveat travels with rounds 7, 8 and 9. The event-drop path remains
unmeasured, because no event was raised during any cut.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS
This commit is contained in:
2026-09-17 01:15:19 +02:00
parent 418f3a2c20
commit 889310ec17
3 changed files with 116 additions and 0 deletions
@@ -379,6 +379,47 @@ public doors **three seconds** after the unblock and reported 530 on all four. T
never have been fair. The re-measurement 43 s later read 200 on all four. The runner measured the
recovery before the recovery could begin — so the runner is the thing that gets fixed, not the note.
### Round 9 — `use` uptime-kuma / accident: **internet cut for ten minutes, hub included**
**23:00:50Z–23:12:00Z.** The first cut of the night that really removed the hub. The injector was
corrected between rounds 8 and 9; the drawn action, app and accident were **not** changed.
| the five things | |
|---|---|
| what the customer saw | **Nothing at home.** uptime-kuma answered 200 on all three reads during the action, and all four front doors read 200 at both post-accident readings. 26 apps before, 26 after, never fewer. |
| what the box did by itself | Kept every container running while it was cut off from the hub **and** from its own host agent. Built its report on schedule, tried to push it **three times over 1 m 40.8 s**, gave up, and carried on serving. Both links repaired themselves the instant the block lifted — no restart, no repair action, nothing from me. |
| time to steady | The apps never left steady. The doors read 200 at the first reading, **2 s** after the unblock, and again 63 s later. |
| alarm fired / true? | **none fired, and none should have** — `node_stale` is a 30-minute threshold. Nothing false was raised. |
| should have fired, did not | **none** — but see the near-miss below, which is a finding in its own right. |
**What a lost report costs: measured, not assumed.**
```
23:08:42 [INFO] [scheduler] Running job: hub-report
23:08:42 [INFO] [report] Building system report
23:10:23 [WARN] [report] Push failed: … context deadline exceeded
23:10:23 [ERROR] [scheduler] Job hub-report failed: hub push failed after 3 attempts (took 1m40.813s)
```
Three attempts, then it stops. Nothing is queued. It gave up **31 seconds before** the link returned.
And that is correct: a report is a **snapshot**, so a lost one costs nothing — the next snapshot
carries the same truth, and the controller says so itself („backing off (the 15-min cycle still
reconciles)"). **This is not the event path.** A dropped event is a lost *fact*, not a stale copy of
a picture that will be redrawn. No event happened to be raised during the cut, so the event-drop
behaviour is **still unmeasured** after three rounds of internet cuts.
**The near-miss, which is luck and not design.** Last good report 22:53:43Z; next scheduled
23:23:42Z; `node_stale` trips at 30 minutes. The gap is **29 m 59 s**. The staleness threshold is
exactly twice the report cadence, so **a single failed push spends the entire budget** — one second
of ordinary jitter and the operator is paged about a box that was healthy throughout and had already
repaired itself. Filed as a register row.
**A second fidelity fault in my accident, named like the first.** The cut also severed the controller
from its host agent (`GET /backup/tiers` to the link-local `169.254.253.1` timed out twice). In a
real house an ISP outage does not do that — controller and agent share one machine. So „internet
gone" as injected is **broader than its name**: internet, hub *and* local agent. No further internet
cuts are drawn, so the injector stays as it is and this caveat travels with rounds 7, 8 and 9.
### Rounds 8-12
PENDING
@@ -0,0 +1,74 @@
round 9 armed for 2026-09-16T23:00:48Z (use uptime-kuma + internet cut, hub now blocked too)
=== round 9 launched 2026-09-16T23:00:50Z (due 23:00:48Z) ===
2026-09-16T23:00:50Z ================ ROUND 9 : use uptime-kuma, while: internet-gone-10min ================
2026-09-16T23:00:52Z --- BEFORE --- containers=26 status=200 status=200 paste=200
2026-09-16T23:00:52Z (immich/photos is a KNOWN PRE-EXISTING failure — not caused by this round)
2026-09-16T23:00:52Z --- ACTION: use on uptime-kuma ---
2026-09-16T23:00:52Z status read 1 -> 200
2026-09-16T23:00:53Z status read 2 -> 200
2026-09-16T23:00:53Z status read 3 -> 200
2026-09-16T23:00:53Z --- ACCIDENT: internet-gone-10min (injected after the action started) ---
2026-09-16T23:00:53Z ACCIDENT=internet-gone-10min round=9
2026-09-16T23:00:54Z blocking the box traffic off-LAN at the HOST, on tap336i0; the LAN stays up EXCEPT the hub (192.168.0.192)
2026-09-16T23:00:54Z blocked (LAN allowed EXCEPT the hub at 192.168.0.192, everything else dropped) - 10 minutes
2026-09-16T23:10:54Z unblocked; host sysctl restored to 0 and both rules removed
-P FORWARD ACCEPT
2026-09-16T23:10:55Z accident internet-gone-10min complete
2026-09-16T23:10:55Z --- AFTER: what the box did BY ITSELF ---
2026-09-16T23:10:56Z t+603s containers=26 (before 26)
2026-09-16T23:10:56Z STEADY after 603s
2026-09-16T23:10:56Z front doors, FIRST reading at 2026-09-16T23:10:56Z - TOO EARLY to trust if the accident just ended:
2026-09-16T23:10:57Z status=200 status=200 paste=200 wiki=200
2026-09-16T23:11:57Z front doors, SECOND reading at 2026-09-16T23:11:57Z, 60 s later - THIS is the one to trust:
2026-09-16T23:11:58Z status=200 status=200 paste=200 wiki=200
2026-09-16T23:11:59Z household lines this round: 12 failures: 0
2026-09-16T23:11:59Z --- alarms ---
| Time | Severity | Type | Message | Source
| Sep 16 21:59 | error | whole_guest_backup_failed | Whole-guest backup FAILED on the local tier — retrying with backoff (next attempt in 15m0s) | controller
| Sep 16 21:53 | info | controller_started | Controller elindult (0.245.0) | controller
| Sep 16 21:48 | info | health_recovered | Rendszer állapot helyreállt: ok (volt: fail) | controller
| Sep 16 21:43 | error | health_critical | Rendszer állapot kritikus (volt: ok) | controller
| Sep 16 21:28 | info | controller_started | Controller elindult (0.245.0) | controller
| Sep 16 21:23 | info | app_deployed | Alkalmazás telepítve: BookStack | controller
| Sep 16 21:22 | info | app_deploy_started | Alkalmazás telepítése elindult: BookStack | controller
| Sep 16 21:22 | info | app_removed | Alkalmazás eltávolítva: bookstack | controller
2026-09-16T23:12:00Z ================ END ROUND 9 ================
[exited with code 0]
## THE MEASUREMENT THE NIGHT WAS MISSING (2026-09-16T23:12Z)
With the injector fixed, the hub really was unreachable this time. The controller's own log:
23:08:42 [INFO] [scheduler] Running job: hub-report
23:08:42 [INFO] [report] Building system report
23:10:23 [WARN] [report] Push failed: Post "https://hub.felhom.eu/api/v1/report":
context deadline exceeded (Client.Timeout exceeded while awaiting headers)
23:10:23 [ERROR] [scheduler] Job hub-report failed: hub push failed after 3 attempts
(took 1m40.813s)
So the behaviour is now measured, not assumed:
* the report was built, attempted THREE times, and then GIVEN UP after 1 m 40.8 s;
* it gave up at 23:10:23, THIRTY-ONE SECONDS before the link came back at 23:10:54;
* nothing was queued. The next report is simply the next scheduled one.
The earlier WARN says so in plain words: "backing off (the 15-min cycle still reconciles)".
That is the design: the report is a SNAPSHOT, so a lost one costs nothing - the next snapshot
carries the same truth. It is NOT the same as the event path, where a dropped event is a lost
FACT. No event happened to be raised during this cut, so the event-drop path is STILL unmeasured.
### A SECOND fidelity fault in my accident, recorded like the first.
The cut also severed the controller from its own HOST AGENT:
23:03:56 / 23:08:56 [ERROR] [quiesce] cycle error: check due: agentapi:
GET /backup/tiers: Get "https://169.254.253.1:8443/backup/tiers": context deadline exceeded
169.254.253.1 is the link-local address of the agent on the host side of the same tap. My blanket
DROP is "everything not in 192.168.0.0/24", so it took the agent link with it.
In a real house an ISP outage does NOT cut the controller from the agent - they sit on one machine.
So "internet gone" as injected is BROADER than its name: it removes the internet, the hub, AND the
local host agent. Stated so nobody reads more into rounds 7-9 than was actually tested.
No further internet cuts are drawn (rounds 10-12 are hard reset, drive pulled, nothing), so the
injector is left as it is and this caveat travels with the three rounds that used it.
### How close the staleness alarm came, by luck, not by design.
Last good report 22:53:43Z. Next scheduled 23:23:42Z. node_stale trips at 30 minutes.
The gap is 29 m 59 s. One second more and the operator would have been paged for a box that was
perfectly healthy and had already repaired itself. That is worth a register row.
+1
View File
@@ -731,6 +731,7 @@ class (an image `VOLUME` at an unmounted path) is still live — `immich-server`
| **R-546** | **[P2-MEDIUM] The first-hour guide sends the household to create their recovery code at a moment when the box cannot yet do it — and the new reminder bar urges them there on every page.** MEASURED 2026-09-16/17 on a fresh box (`tester-1-022354`, guest 9201, controller 0.245.0, agent 0.131.0, installed from the published ISO 1.28.0). `VOLUNTEER-first-hour.md` §6 — added hours earlier in controller v0.245.0 — places „A helyreállítási kód" immediately after the dashboard password and **before the first app**, because until it is done the off-site copy does not run. At exactly that point the ceremony FAILS: `POST /api/escrow/start` → 200, then `GET /api/escrow/status` → `detail: "exit 2: … selftest=escrow-create requires -storage <pbs-storage-id> (or escrow.pbs_storage…"`, and `POST /api/escrow/claim` → **409** „A folyamat jelenlegi állapotában a kód nem kérhető le." **Cause, measured on both sides:** the hub had auto-provisioned the DR descriptor at 20:19 (no press — see R-534/R-511's acknowledged-delete path) and its Backup & DR panel itself read „descriptor provisioned … **waiting** · ceremony possible once the descriptor is applied on the box"; the box had no PBS storage (`pvesm status` = local + local-lvm only) and `/etc/felhom-agent/agent.json` had **no `escrow` section at all**. **It is a TIMING gap and it self-heals:** a watcher left the box alone and polled — `pbs_storage` and `escrow.pbs_storage_id` both became `felhom-pbs` at **20:35:16Z, ~17 minutes after the bind**; the retried ceremony then passed every preflight item and the claim returned 200 (83-character code, entropy 129.2 bits), and `escrow_state` flipped to `escrowed`. **Why it still matters:** for those ~17 minutes the R-543 reminder bar (also v0.245.0) is on *every* page telling the household to do the one thing that refuses, and nothing on the page says „wait a few minutes" — the volunteer meets a stderr fragment about a `-storage` flag. **Fix shape (one of):** have the escrow page/bar consult `preflight` and say „a doboz még készül — pár perc múlva próbáld újra" while `pbs_storage_id` is unset; or move the guide's step to after the first app; or make the bar appear only once preflight is green. **No product code was changed tonight** (validation run). Evidence: `audits/evidence-chaos-night-2026-09-17/phase0-escrow-failure.txt` and `phase0-escrow-retry.txt`. | **READY — rank P2-MEDIUM; owner: CC (controller copy + guide timing)** |
| **R-547** | **[P3-LOW] A disk that fills and empties between sweeps is never mentioned to anyone: `disk_critical` is defined at ≥95 % used, but the fill-watch runs once a day.** MEASURED 2026-09-17 (chaos night) on a fresh box (`tester-1-022354`, controller 0.245.0): the customer guest’s root filesystem was held at **96 % for ten minutes** (29 G used, 1.5 G free) and **no alarm of any kind fired** — checked twice, once by the round’s own runner and once independently after the fill was released. Cause, established from the ladder BEFORE the round rather than after: `fillwatch` runs **daily at 03:30** plus once ~90 s after a controller start, so a ten-minute window contains no check unless a restart lands inside it. The timing here was almost comic — the controller restarted at 21:28 after the previous round’s power cut, so its one opportunistic check ran about **twenty seconds before** the disk filled. Meanwhile all twelve apps kept serving and the background household loop logged 12 operations with 0 failures, so nothing else would have hinted at it either. **This is the ladder working as designed, not a missed alarm** — the fill-watch is a daily sweep, not a monitor. It is filed because the honest answer to „would the household be told their disk is full?” is **no, unless the controller happens to restart while it is full**, and that answer is not written down anywhere. **Fix shape (one of):** sample the fill more often than daily (a cheap `statfs` on the 5-minute health pass would do it); or say plainly in `08-alarm-ladder.md` that a transient full disk is out of scope. Evidence: `audits/evidence-chaos-night-2026-09-17/round-3.txt`. | **READY — rank P3-LOW; owner: CC** |
| **R-548** | **[P3-LOW] The whole-guest backup’s LOCAL tier cannot fit on a small-system-disk box, and will retry on that tier for ever.** MEASURED 2026-09-17 (chaos night) on `tester-1-022354`: a whole-guest backup wrote a **~29 GB source** (`mp0` = `local-lvm:vm-9201-disk-1`, 70 G provisioned, 40.58 % used, `backup=1`) into `pve-root`, which on a 32 GB system disk is **14 GB total with ~4.9 GB free**. Two samples thirty seconds apart showed the archive growing ~497 MB while free space fell ~475 MB — **~16 MB/s, i.e. under four minutes to a full `/`** on the nested PVE. **The product’s behaviour is correct and legible throughout:** it failed the tier and said which one — `whole_guest_backup_failed` (error, operator-only): „Whole-guest backup FAILED on the local tier — retrying with backoff (next attempt in 15m0s)” — its status surface agreed (`target_id:"local"`, `success:false`, `size_bytes:0`), and the **off-site tier then ran from the same snapshot and succeeded in ~8½ minutes, encrypted to ep0, consuming no local disk at all**. So the data still left the house. What is filed is the loop: on a box shaped like this the local tier can **never** succeed, and it keeps retrying on a backoff for ever, burning I/O and risking `/` each time. **Honest caveat:** the 32 GB system disk is this drill’s fixture choice, so the row is conditional on disk size — but nothing in the product checks whether the local target could ever hold the source before trying. **Fix shape:** compare the source size against the target’s free space before starting the local tier and skip it with a clear reason, rather than discovering it at ~16 MB/s. Evidence: `audits/evidence-chaos-night-2026-09-17/round-6.txt`. | **READY — rank P3-LOW; owner: CC** |
| **R-549** | **[P2-MEDIUM] The staleness alarm's budget is exactly two report cycles, so ONE failed push spends all of it.** MEASURED 2026-09-17 (chaos night, round 9) on `tester-1-022354` (controller 0.245.0): hub reachability was removed for ten minutes from the VM's side. The controller built its 23:08:42Z report, retried the push **three times over 1 m 40.8 s**, and gave up at 23:10:23Z (`hub push failed after 3 attempts`) - **31 seconds before the link returned**. Nothing is queued, and that is correct: a report is a snapshot, so the next one carries the same truth, and the controller says so itself ("backing off (the 15-min cycle still reconciles)"). **The arithmetic is the finding.** Last good report 22:53:43Z; next scheduled 23:23:42Z; measured cadence **15m0s**; `node_stale` trips at **30 minutes**. The gap is **29 m 59 s** - one second inside the threshold. So a single missed push spends the whole staleness budget, and any ordinary jitter pages the operator about a box that is healthy, serving every app, and has already repaired itself unaided. **The product behaved correctly throughout:** no false alarm fired, no app stopped, and both the hub link and the host-agent link recovered by themselves the moment the block lifted. What is filed is the margin, not a misbehaviour. **Fix shape:** either set the staleness threshold to a clear multiple of the cadence (three cycles, not two), or let a push that has failed all three attempts retry once off-cycle instead of waiting for the next scheduled report. **Honest caveat:** the cut was injected by the drill and also severed the controller from its host agent, which a real ISP outage would not do - but the report arithmetic above depends only on the hub being unreachable. Evidence: `audits/evidence-chaos-night-2026-09-17/round-9.txt`. | **READY - rank P2-MEDIUM; owner: CC** |
| **R-537** | **[P1-HIGH] The app-backup page labels the tier-1 backup „DB + Konfig + Adatok" and prints the app's data-drive size next to it — but the tier-1 unit contains NO drive-side app data at all.** MEASURED 2026-09-16 on the drill box (fresh install, controller 0.243.0, one drive, tier 2 and tier 3 both „Nincs beállítva"): five photos (3 000 000 B) were uploaded into Nextcloud through its own WebDAV interface, then the customer-visible „Mentés most" was pressed (`POST /api/backup/run` → 200, the unit grew 25 337 B → 978 MB). The resulting unit's `manifest.json` lists `db-dumps` + three **docker volume** dumps and nothing else; listing the 781 MB `nextcloud_nextcloud_html.tar` (29 346 entries, positive control `version.php` = 3 hits) gives **`Fotok` = 0 and `nyaralas` = 0**, and `./data/` is the empty bind-mount point. A `find` over the whole `backups/` tree for `*appdata*` / `*Fotok*` returns nothing. The page nevertheless renders „1. mentés … DB + Konfig + Adatok" and „Nextcloud Adatlemez 65.1 MB" — a size measured on exactly the data it does not copy (`internal/web/handlers.go:1176-1178`, `BackupContents`). **This is a truth defect, not a design defect:** `07-backup-architecture.md` §6.2 places nextcloud's file leg at **Tier 2 and Tier 3 only**, and its „[FACT] What the whole-guest tiers do NOT carry" says `mp8 /mnt/felhom-drives` is out of vzdump scope (confirmed live: „excluding bind mount point mp8 … (not a volume)"). So on a one-drive box with no off-site tier — the state every fresh install starts in — the household's files are in **no backup**, while the page says „Adatok". Same family as R-517/R-518. **Fix shape:** render tier-1 contents from the capture set actually written (`ComputeCaptureSet`), so a unit with no file leg reads „DB + Konfig" and the drive size is not shown beside it; and say on the page that the app's files need tier 2 or tier 3. Evidence: `audits/evidence-drill-0243-2026-09-16/phase2-f10.txt`. **CLOSED 2026-09-16 — controller v0.244.0, proven live.** The contents label is computed PER TIER from what that tier captures: Tier 1 says „Adatok" only when the app's data really is in the volumes the unit captured, and a class-A app carries one sentence saying where its files ARE protected. Proven on demo-hp through the page the customer opens: Paperless-ngx reads „1. mentés … DB + Konfig" with „Az alkalmazás fájljait a távoli másolat (és a második meghajtó) védi …", while its „2. mentés" row still reads „DB + Konfig + Adatok". Red-proof: restoring the old app-shaped label fails `TestAppBackupRows_Tier1LabelDoesNotClaimFilesItCannotHold`. **RE-PROVEN 2026-09-16 on a FRESH box** (installed from the built ISO 1.28.0, controller 0.244.0, off-site on by default): the Nextcloud row read „1. mentés … DB + Konfig" with the new sentence, „2. mentés … Nincs 2. (off-drive) másolat", „3. mentés Sikeres restic → …your-storagebox.de"; „DB + Konfig + Adatok" appeared ZERO times while the local unit held no file leg. | **CLOSED 2026-09-16 — controller v0.244.0 (proven live on demo-hp)** |
| **R-538** | **[P1-HIGH] A tier-1 app restore reports plain success and leaves Nextcloud listing files whose bytes were never in the backup — and it destroys the app's own trash, the customer's last copy.** MEASURED 2026-09-16 on the drill box, F10 („a child deletes the photo folder"): the five photos were deleted through Nextcloud (DELETE 204, PROPFIND 404), then restored through the page exactly as a customer would (`POST /backup/restore` `stack_name=nextcloud` `snapshot_id=helyi` → 302, finished in **35 s**, „A(z) nextcloud: 3 adatkötet és az adatbázis visszaállítva — az alkalmazás újraindult."). Afterwards the folder is back and **lists all five photos**, and **none of them opens**: `GET nyaralas-1..5` = 404 / 503×4 with `Sabre\DAV\Exception\NotFound`, while the positive controls at the same moment pass (`status.php` 200, WebDAV PUT 201, GET 200). Cause: the replayed MariaDB dump (11:01:45Z) knows the photos, the bytes live on `mp8` and were never captured (R-537). **Worse:** the bytes were still on the drive in Nextcloud's own trash (`appdata/nextcloud/admin/files_trashbin/files/Fotok.d1789556707/nyaralas-1..5.jpg`, all five present) and the restored database no longer references them — the trash listing comes back **empty**, so „restore from trash", the one route that would have worked, is gone. The customer is left with five unopenable photos, a success message, and no warning. **Fix shape:** before replaying a database whose app has an uncaptured file leg, refuse or warn („ennek az alkalmazásnak a fájljai nincsenek ebben a mentésben — a visszaállítás után a fájlok hiányozni fognak"); and never present a DB-only restore of a class-A app as a complete one. Evidence: `audits/evidence-drill-0243-2026-09-16/phase2-f10.txt`. **CLOSED 2026-09-16 — controller v0.244.0, proven live.** A unit restore refuses before anything is touched when the unit cannot return the app's drive-side files, and names the route that can. Fired live on demo-hp: `POST /backup/restore` for paperless-ngx → 302 with „Ez a mentés nem tartalmazza az alkalmazás fájljait, ezért nem állítjuk vissza az adatbázist föléjük — a fájlok így a helyükön maradnak. A fájlok a távoli másolatból állíthatók vissza …", and the app read `running` before AND after, so nothing was stopped and no trash was made unreachable. The database-and-settings-only path exists as a separately worded second step. Red-proof: disabling the guard fails `TestUnitRestore_RefusesWhenTheUnitCannotHoldTheFiles`. **RE-PROVEN 2026-09-16 on a FRESH box, and this time the refusal had somewhere to point:** after five photos were deleted, `POST /backup/restore` was refused with „…a fájlok így a helyükön maradnak. A fájlok a távoli másolatból állíthatók vissza: … „Teljes visszaállítás (fájlok + adatbázis)"", the app read `running` before AND after, and the wastebasket was untouched. The off-site route then returned all five photos — 200 with the exact uploaded sizes and sha256 IDENTICAL to the originals, 5/5, with a negative control. Evidence: `audits/evidence-backup-promise-2026-09-16/phaseE-photos.txt`. | **CLOSED 2026-09-16 — controller v0.244.0 (proven live on demo-hp)** |
| **R-525** | **[P3-LOW] FileBrowser has its own login; putting it behind the dashboard session (traefik forwardAuth or Quantum proxy auth) is a new mechanism nobody has measured.** Filed 2026-09-15 by the P1-fixes task (B.5). R-513 closed the default-password hole with a generated password; a household still has two logins. **What it needs:** a spike on a scratch guest — forwardAuth to the controller session, and what FileBrowser Quantum does with a trusted header. | **READY — rank P3-LOW; owner: CC (spike)** |