Files
felhom.eu/documentation/audits/DRILL-chaos-night-2026-09-17.md
T
admin eb638d303b
gates / gates (push) Successful in 22s
CHAOS NIGHT rounds 4-5: the box repairs its own tunnel, and survives docker dying
Round 4 (tunnel killed 10 min): cloudflared came back in ~97 seconds and the
CONTROLLER did it, not Docker - RestartCount=0 proves the unless-stopped policy
never acted, and the log shows the protected-infra recovery redeploying it.
health_critical fired at 21:43 and health_recovered closed it at 21:48, so the
alarm was not a dead end.

Round 4's drawn ACTION never ran, and that is recorded rather than re-run: the
round-2 power cut rebooted the guest, /tmp is cleared on boot, and the dashboard
password lived there. The off-site run was never triggered. Re-running a round
after watching it fail is how a drill starts choosing its own results. The file
now lives in /root, so round 10's hard reset cannot disarm rounds 6, 8 and 10.

Round 5 (docker restarted): all 26 containers back in 16 seconds, doors serving
again in ~40, controller_started true and correct, nothing missed. The household
loop is recorded as NOT SAMPLED - 0 lines because the round was shorter than its
2-minute sampling interval, which is not the same as 0 failures.

Two traps avoided and written down: round 5's own alarm snapshot was taken six
seconds after the controller started, from which controller_started looked
missing (it fired); and my check for the password file put its redirect on the
wrong host, reporting "not there" for a file that was present all along. Tenth
and eleventh of the same family tonight - a check whose own precondition was
wrong, answering confidently.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS
2026-09-16 23:56:26 +02:00

21 KiB
Raw Blame History

DRILL — CHAOS NIGHT: random actions on random apps while random things go wrong (2026-09-16/17)

Interventions: PENDING — the run is in progress. Ready for a volunteer: PENDING. The accident-plus-action pair that hurt most: PENDING.

Baselines, verified live against Gitea at 21:49 CEST 2026-09-16 (not copied from the brief): felhom-controller 714d5bce0920 v0.245.0 (MinAgent 0.131.0) · felhom-agent e98b857684f4 v0.131.0 · felhom.eu d124c77e176d hub v0.116.0, ISO 1.28.0 published · app-catalog 94bc5febaca2. All four trees clean and in sync. Highest register row R-545, 212 open. Golden waiver valid to 2026-09-27. Customer tester-1 (enkicsifelhom.hu, tester1@felhom.eu, no host). Venue: demo-hp (Tier 0), a fresh nested VM, disk on the NVMe at its root. Evidence: evidence-chaos-night-2026-09-17/.

The schedule — drawn ONCE, before round 1, and written here first

The point of this section's position in the document is that the night could not be chosen after the fact. chaos_schedule.py is committed beside the evidence; re-running it reproduces this table.

  • seed: 20260917 (the date)
  • script sha256: 4b98afe65d042df7e7dc417553b33565cfbb4afd451c68456a7cabec0858d2a1
  • generator: evidence-chaos-night-2026-09-17/chaos_schedule.py, stdlib random seeded with the seed
# time X — the action Y — the app Z — the accident
1 23:30 offsite-run adventurelog nothing
2 23:55 restore gokapi power cut
3 00:20 use bookstack disk 95% full
4 00:45 offsite-run mealie tunnel down 10min
5 01:10 use privatebin docker restarted
6 01:35 backup-system adventurelog nothing
7 02:00 update nextcloud internet gone 10min
8 02:25 backup-app nextcloud internet gone 10min
9 02:50 use uptime-kuma internet gone 10min
10 03:15 restore uptime-kuma hard reset
11 03:40 use paperless-ngx drive pulled 20min
12 04:05 use paperless-ngx nothing

Re-draw log — a silent re-draw is a schedule chosen by the person running it, so every one is here:

  • r02 X=reinstall re-drawn (nothing has been removed yet)
  • r06 Z=disk 95% full re-drawn (constraint 4: at most once)
  • r07 Z=nothing re-drawn (constraint 6: never two in a row after r2)
  • r08 X=reinstall re-drawn (nothing has been removed yet)

What the draw happened to give, said plainly before the night judges it: no remove round was ever drawn, so reinstall had nothing to reinstall and was re-drawn twice (rounds 2 and 8). Three internet gone rounds land consecutively (7, 8, 9) — that is the seed's doing, and it makes rounds 7–9 a de-facto endurance test of the same accident against three different actions rather than three independent samples. controller killed, drive pulled 90s, memory pressure, agent restarted and hub unreachable were never drawn at all; this night does not test them, and the morning verdict must not claim it did.

Phase 0 — the golden, the box, the household

0.1 Golden 0.245.0, baked and published. Launched 19:52:47Z as a transient unit in the drill VM, finished 19:58:15Z. Markers: overlay2=1, including mount point=2, upload OK (HTTP 201)=1, FATAL=0, publish-skipped=0. GOLDEN_SHA256=7a08aa1ad0bdd622247e1901e422ed2f72df22ef531a144135a44b66fc455626. The teardown was gated on the REGISTRY answering 200, not on an exit code — and that mattered: the wrapper exited 144 while every measured outcome was good. Vouched in the hub and read back from the page (golden currently vouched: 0.245.0). The three bake failures of 2026-09-16 (scp -P, chmod 0700, GITEA_USER=admin) were each guarded and none recurred.

Decision, recorded because silence reads as agreement: the global controller floor was left at 0.244.0. The new box installs golden 0.245.0, which already carries controller 0.245.0, so no floor was needed to deliver anything tonight; raising it would have pushed an update onto demo-felhom, a box not in this drill.

0.2 The box. VM 336 on demo-hp: 8 GiB, 4 cores, 32 G system + 100 G data disk on the NVMe at its root, booted from the published ISO 1.28.0. Boot order set in its own qm set (combining it silently yields order=net0;ide2). Install completion was judged from the disk — blocks used grew 3233 → 6942 MiB then held across three checks — because „Automatically reboot" is ticked and a finished install looks exactly like a stuck one on screen. The summary page was read before pressing Install, and the line that made it safe was „Disk(s): /dev/sda" — the 32 G system disk alone.

The walk, as a volunteer, cost ZERO operator presses. The box registered itself as an unclaimed appliance and polled, visibly, until bound. The bind link came from the waiting mail (minted 18:17:46Z by yesterday's acknowledged host delete), the pairing code off the box's own console (4SY-4TX), the „Tulajdonosi jelmondat" from the hub's customer record: POST /bind/ -> 200, „Sikeres összekötés." Then day-0 ran on its own and the hub recorded, without anyone pressing anything: appliance_bound (customer_selfbind) · appliance_credential_delivered · claim_reissued_reenroll · offsite_reissued · pbsdr_auto_reissue — „Previous key destroyed (acknowledged deletion) — credentials re-issued automatically."

That last event is a first. The brief named „the WG hook provisions by itself after an acknowledged delete" as a claim never measured live. It ran tonight, unprompted. Both pre-declared presses (O1 self-bind, O2 re-issue) were therefore unnecessary.

The dashboard was claimed with the mailed code and proven by logging in with the new password — a claim page that re-renders looks identical to success from the status code alone. The 100 GB data drive was initialised through the wizard's own endpoint (POST /api/storage/init, polled to phase: done), and df shows it mounted at /mnt/felhom-drives/hdd_1 with 93 G free.

The box landed on tonight's golden with no hand upgrade: controller 0.245.0 (healthy), agent 0.131.0, host tester-1-022354 ONLINE. And the R-543 escrow reminder bar shipped hours earlier was live on it, on a box nobody had touched.

0.3 The household — and the first real trouble. Twelve deploys were fired; ten were accepted, two refused for memory with both numbers quoted. Then nine of the ten failed: the guest's disks are thin-provisioned over an ~11.8 GB pool carved from a 32 GB system disk, ten simultaneous image pulls filled it, and the hub recorded storage_fill_critical (100 %) plus nine app_deploy_failed warnings, one per app, each naming the failing pull. Only PrivateBin installed.

The product behaved; the harness did not. R-536's failure event — shipped that same morning so an interrupted install is not silence — fired for all nine within two minutes. The memory guard refused rather than over-committing. The per-stack record stayed honest (deployed: false). The two faults were mine: firing twelve deploys in two seconds is not household behaviour, and a 32 GB system disk was copied from an earlier drill without checking what that drill had installed.

0.4 The escrow ceremony could NOT be completed — and this one is about tonight's own release. See „Finding: the recovery-code step cannot be done when the guide says to do it" below.

Finding: the recovery-code step cannot be done when the guide says to do it (R-546)

The box was at exactly the point of the guide this release added hours earlier — installed, bound with no press, claimed, drive initialised, no apps yet — and the escrow reminder bar was on every page telling the household to create their recovery code. It could not be done.

POST /api/escrow/start   -> 200   {"job_id":"escrow-1789590499667361664","phase":"running"}
GET  /api/escrow/status  -> claimable:false —
     detail: "exit 2: … selftest=escrow-create requires -storage <pbs-storage-id> (or escrow.pbs_storage…"
POST /api/escrow/claim   -> **409** „A folyamat jelenlegi állapotában a kód nem kérhető le."

Both sides agreed on the cause. The hub's own Backup & DR panel read „host enrolled done · WG tunnel peer registered done · descriptor provisioned (namespace tester-1, token felhom@pbs!tester-1) waiting · ceremony possible once the descriptor is applied on the box". The box had no PBS storage (pvesm status: local, local-lvm only) and no escrow section in agent.json at all.

It self-heals, and that was measured rather than assumed. The box was left alone and polled:

20:30:12Z … 20:34:15Z   pbs_storage=none         escrow.pbs_storage_id=none
**20:35:16Z              pbs_storage=felhom-pbs   escrow.pbs_storage_id=felhom-pbs**

~17 minutes after the bind. The retried ceremony passed every preflight item, the claim returned 200 (83-character code, 129.2 bits of entropy, revealed once), and escrow_state became escrowed. The bar then vanished from all four pages checked — the R-543 fix working through its whole lifecycle on a box nobody had set up for the test.

So the defect is timing and wording, not mechanism. For ~17 minutes a volunteer following tonight's guide meets a stderr fragment about a -storage flag, while every page urges them on. Filed R-546 (P2). No product code was changed — this is a validation run.

Phase 1 — the rounds

Rounds run at ~25-minute spacing. The schedule above is fixed; only the wall-clock start moved, because Phase 0 ran long (the storage wizard submits by JavaScript and the endpoint was worked out rather than guessed). Round 1 began 23:07 CEST.

Round 1 — offsite-run / adventurelog / accident: nothing (control round)

the five things
what the customer saw „A távoli mentés elindult — az állapot itt frissül." and, at the end, „A távoli mentési tároló elárvult: a benne lévő mentések egy korábbi, már nem elérhető kulccsal készültek (újratelepítés)."
what the box did by itself walked all twelve apps — stop, dump each volume with real byte counts, restart — captured eleven, could not capture the one that was crash-looping, and finished
time to steady 1m45s (last_duration), last_run 21:09:00Z, progress.active false, last_error empty. A control round: the box never left steady
alarm fired / true? three, all true — app_start_failed named Nextcloud · backup_run_failures „1 of 12 apps failed to back up in this nightly run: nextcloud" · offbox_repo_orphaned, matching the status endpoint's own "orphaned": true
should have fired, did not none

Household loop in the window: 3 lines marked FAILED, all three mine — the loop counted the dashboard's 301 redirect as a failure while accepting the same 301 for app reads. Fixed at 21:11:25Z and marked in the log; only lines after that marker are scored.

What round 1 actually establishes. The off-site tier is armed (escrowed) and the run works end-to-end, but on THIS box — a rebuild for an existing customer — the remote repository was written under a key the box no longer holds, so no snapshot was written. That is the documented rebuild behaviour, surfaced honestly with the route out named in the message rather than reported as success.

Two things that looked like defects in this round and are not, both established with controls rather than inference — five front doors answering 404 (traefik has no route to an unhealthy container; identical byte-for-byte to a no-such-host control) and a crash-looping Nextcloud (image layers corrupted while my thin pool stood at 100 %; „invalid ELF header", repaired by a re-pull). Detail in evidence-chaos-night-2026-09-17/round-1-notes.txt.

Phase 0 postscript — repairing my own damage, and three conclusions I had to retract

Nine of the first ten deploys failed because I fired twelve at once onto a thin pool carved from a 32 GB disk, and the pool hit 100 %. Repairing that took the rest of Phase 0 and produced two distinct faults of mine, with different cures, which only separating them made fixable:

fault symptom cure
image layers written while the pool was full php: … libxml2.so.2: **invalid ELF header**, exit 127 crash loop drop the image, let compose pull it again
my re-seed generated fresh database passwords over volumes already initialised with the first set Postgres auth_failed, MariaDB „Access denied for user … (using password: YES)" remove the app with its data, deploy once with one consistent secret set

A fresh image did not fix gokapi and a fresh database did — that is the evidence the two faults are different things rather than one.

Three conclusions I wrote and then had to retract, each corrected where it stood:

  1. „the five 404s were my mistimed sweep" — wrong for four of them. A negative control (a no-such-host request) returned the identical 404 of 19 bytes, and a positive control returned 200/1200 bytes: traefik simply has no route to an unhealthy container.
  2. „nextcloud is repaired" — wrong. The re-pull fixed the crash, and the app still could not reach its database. The container reported healthy throughout, because the image's own healthcheck asks whether Apache answers, not whether the application works.
  3. „all the broken apps are corrupt layers" — wrong. bookstack logged a clean startup, gokapi logged nothing at all, immich showed a Postgres auth failure.

I also nearly filed a defect against the drive gate, which was working and logging at DEBUG while I read a settings snapshot inside its 30-second tick. An absent log line is not evidence.

None of this is a product defect and none of it is filed as one. What the product did throughout was correct and legible: it refused to route to unhealthy containers, app_start_failed named the app that was down, backup_run_failures said „1 of 12 … nextcloud", the memory guard refused the eleventh and twelfth installs with both numbers quoted, and storage_fill_critical fired at 100 %.

Round 2 — restore gokapi / accident: power cut, 20 s into the restore

the five things
what the customer saw „Visszaállítás elindult — az állapot itt frissül." then the box went dark mid-restore; on return the dashboard and every app were back
what the box did by itself everything — containers 0 → 25 at t+131s → 26 at t+148s, nothing stuck, no shell used. gokapi, the app being restored when the plug came out, returned Up 30 seconds (healthy)
time to steady 148 s, measured against the container count this round took itself before the accident
alarm fired / true? controller_started (info) — true and correct. No false alarm.
should have fired, did not none — per the ladder a 60-second outage yields no node_stale (30 min threshold) and no app_start_failed (90 s boot grace), and neither appeared

Household loop: NOT COLLECTED. The loop was a transient unit on the VM and died with the power cut — the first accident that could have produced household failures instead produced no lines at all. Zero lines is not zero failures, so it is recorded as not collected, and the loop is now a persistent systemd unit that returns with the box.

A finding this round handed over: app_oom (warning) — „Alkalmazás memóriája elfogyott: immich (immich-postgres) — egy folyamatát a memóriakorlát leállította". That is immich's whole mystery solved: its Postgres was OOM-killed during the reverse-geocoding import, which is why the server saw CONNECTION_CLOSED and crash-looped twelve times. The controller caught an OOM inside an LXC guest and named the exact container — worth recording against this project's standing finding that those signals are usually invisible there. The diagnosis I spent twenty minutes reaching from logs was in the alarm feed, correctly labelled, the whole time.

Round 3 — use bookstack / accident: system disk filled to 96 % for ten minutes

the five things
what the customer saw nothing. wiki, status and paste all answered before, during and after. No banner, no warning, no mail — the household was never told the disk was full
what the box did by itself kept all twelve apps running on a 96 %-full root filesystem and released the space cleanly when the fill was removed (29 G used → 944 M used). The shared thin pool never moved (39.69 %) and the filesystem stayed writable
time to steady the box never left steady — 26 containers before, 26 after, none restarted
alarm fired / true? none fired, checked twice independently after the fill was released
should have fired, did not disk_critical is defined at ≥95 % used and the disk sat at 96 % for ten minutes. But this is the ladder working as designed, not a miss: the fill-watch is a daily sweep (03:30) plus one check ~90 s after a controller start. Predicted before the round, confirmed after

Household loop: 12 operations, 0 failures. The household kept using its apps normally throughout.

The finding is the silence. 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. Here the timing was almost comic: the controller restarted at 21:28 after round 2's power cut, so its one opportunistic check ran about twenty seconds before the disk filled, and the next is not due until 03:30.

A correction, recorded where it happened: I twice labelled a mid-window reading „end of window", estimating the clock instead of reading it. The readings were unchanged, but „nothing yet, five minutes in" and „nothing in the whole window" are different findings. From here the end-of-window check is taken when the round's own runner reports completion.

Round 4 — offsite-run (mealie) / accident: tunnel killed for ten minutes

The drawn ACTION never ran. The runner aborted with „no session — mine, not the product's": round 2's power cut had rebooted the guest, /tmp is cleared on boot, and the dashboard password file lived there. Round 3 was a use round and never needed it, so round 4 was the first to find it gone. The accident was measured; the off-site run was not. Recorded as half-measured rather than re-run and presented as whole — re-running a round after seeing it fail is how a drill starts choosing its own results. The file now lives in /root, which survives a reboot.

the five things
what the customer saw from outside, the apps vanished for ~90 s (public route 530) and came back on their own (200); from inside the house, nothing — traefik answered 301 throughout
what the box did by itself repaired its own tunnel. cloudflared killed 21:41:33Z, running again 21:43:07.478Z (~97 s), with RestartCount=0 — so Docker's unless-stopped policy did not do it; the controller's protected-infra recovery redeployed it („[infra] deploying cloudflared →…")
time to steady the apps never stopped; the way IN was restored in ~97 s
alarm fired / true? two, correctly paired — health_critical (error) 21:43, health_recovered (info) 21:48. Exactly what the ladder predicts for a missing protected container, and the alarm was not a dead end
should have fired, did not none for the accident

Household loop: 10 operations, 0 failures — and that number is narrower than it looks. The loop does not follow redirects, so it measures „is the app serving on the box", never „can the household reach it from outside". It saw nothing while the public route was returning 530.

Round 5 — use privatebin / accident: docker restarted inside the guest

the five things
what the customer saw a gap well under a minute: 200 before, 404 two seconds after docker returned (traefik had not re-registered routes), serving again by 21:54:19Z — about 40 s of shut doors
what the box did by itself everything. Restart ran 21:53:27Z→21:53:41Z; all 26 containers back at t+16s; the controller returned with them, waited 51 s for the fleet to settle and found nothing boot-orphaned to repair — correct, since every container had already come back on its own policy
time to steady 16 s to 26 of 26 containers; ~40 s until the doors served. The slower number is the one a household feels
alarm fired / true? controller_started (info) — true and correct, and the only line the ladder expects: no app_start_failed (90 s boot grace), no liveness alarm
should have fired, did not none

Household loop: NOT SAMPLED — 0 lines, because the round lasted ~18 s and the loop samples every 2 minutes. Recorded as not sampled, never as a pass.

A trap avoided. The round's own alarm snapshot was taken six seconds after the controller started, and from it controller_started looked missing. A later reading shows it present at 21:53. An alarm cannot be called missing by a measurement taken before it could have fired.

Rounds 6-12

PENDING

Phase 2 — the morning after

PENDING

Interventions — counted, with the reason for each verdict

PENDING

Teardown — three layers, stated

PENDING