CHAOS NIGHT: round 1 recorded, and three of my own conclusions corrected
gates / gates (push) Successful in 20s
gates / gates (push) Successful in 20s
Round 1 (offsite-run, control round) is written up with its five things: the run worked end to end in 1m45s, and on this REBUILT box the remote repository is orphaned - the documented behaviour, surfaced honestly instead of reported as a successful copy. Three alarms fired, all true and precise. Corrections to my own earlier claims, each recorded where the wrong version was written: - "the 404s were my mistimed sweep" - wrong for four of five. Proven with a negative control (a no-such-host request returns the identical 404, 19 bytes) that traefik simply has no route to an unhealthy container. - "nextcloud is repaired" - wrong. The re-pull fixed the corrupt library, but the app still cannot reach its database, and the container reports HEALTHY the whole time. A health signal is not a data signal. - "all the broken apps are corrupt layers" - wrong. bookstack logged a clean startup, gokapi logged nothing, and immich shows a Postgres auth_failed. The real cause of most of it is mine: my re-seed generated FRESH database passwords over volumes whose databases were initialised with the first set. The affected apps are being removed with their data and redeployed cleanly. Also recorded: an HTTP 000 is "no answer", not "it failed" - the action still took effect. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS
This commit is contained in:
@@ -142,10 +142,42 @@ whole lifecycle on a box nobody had set up for the test.
|
||||
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 twelve rounds
|
||||
## 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`.
|
||||
|
||||
### Rounds 2-12
|
||||
|
||||
PENDING
|
||||
|
||||
|
||||
## Phase 2 — the morning after
|
||||
|
||||
PENDING
|
||||
|
||||
@@ -64,3 +64,119 @@ The only app that was broken is the only app that was named.
|
||||
were written under a key this box does not have. That is the documented rebuild behaviour
|
||||
(„Guest rebuild orphans the off-site repo"), surfaced to the customer rather than hidden, with
|
||||
the route out named in the message.
|
||||
|
||||
## The 404s, settled with controls — and my first explanation was WRONG
|
||||
I first explained the five 404s as „my sweep ran while the backup was quiescing apps". After the
|
||||
backup finished, four of the five were **still** 404, so that explanation was wrong for them. What it
|
||||
actually is, established with both controls rather than by inference:
|
||||
|
||||
negative control nosuchapp.enkicsifelhom.hu -> 404, **19 bytes**, „404 page not found"
|
||||
wiki / share / paperless / photos -> 404, **19 bytes**, „404 page not found" (identical)
|
||||
positive control status.enkicsifelhom.hu -> **200, 1200 bytes**
|
||||
|
||||
Identical to the no-such-host control, byte for byte: **traefik has no route for them.** The apps did
|
||||
not answer 404 — nothing answered. And the reason there is no route is the container state, because
|
||||
traefik only routes to a container that is up and healthy:
|
||||
|
||||
bookstack Up 5 minutes (**unhealthy**)
|
||||
gokapi **Restarting (0)**
|
||||
immich-server **Restarting (1)**
|
||||
paperless-webserver Up 9 seconds (health: starting) <- this one was simply still starting
|
||||
nextcloud Up 20 seconds (health: starting) <- the image re-pull REPAIRED it
|
||||
|
||||
So the sequence is: my disk-full episode corrupted image layers -> containers crash-loop or stay
|
||||
unhealthy -> traefik has no route -> the front door 404s. Nextcloud proves the chain from the other
|
||||
end: drop the corrupt image, let compose pull it again, and the app comes up. The same repair is
|
||||
applied to bookstack, gokapi and immich, with each one's failing log lines captured BEFORE the fix so
|
||||
the cause is recorded and not just the cure.
|
||||
|
||||
**None of this is filed as a product defect** — the corruption is mine. What the product did with it
|
||||
was correct throughout: it refused to route to unhealthy containers, it reported `app_start_failed`
|
||||
for the app that was down, and it named that same app as the one that failed to back up.
|
||||
|
||||
## The nextcloud repair, with its own record (not inferred from a health badge)
|
||||
stop through the product's API -> 200
|
||||
docker image rm nextcloud:34.0.1-apache -> Deleted: sha256:f2ec4de84f559f5c7be4233b589cdbdbb5507807e05621b77320edd55a1f2a0f
|
||||
start through the product's API -> 200 (compose re-pulls the missing image)
|
||||
t+15s nextcloud Up 15 seconds (health: starting)
|
||||
|
||||
That closes the chain from both ends: corrupt layer -> `invalid ELF header` -> exit 127 crash loop
|
||||
-> no traefik route -> 404 at the front door; and then drop the image -> fresh pull -> the app comes
|
||||
up. The repair was done through the product's own stop/start endpoints, not by hand-running compose,
|
||||
so the controller's record of the app stayed consistent throughout.
|
||||
|
||||
## The cause evidence contradicts my own hypothesis — recorded before the repair overwrote it
|
||||
I had assumed all the broken apps were corrupt-layer damage like nextcloud. The logs captured BEFORE
|
||||
touching them say otherwise:
|
||||
|
||||
* **bookstack** — a perfectly normal startup: „Waiting for DB to be available" … „INFO Nothing to
|
||||
migrate." … „[custom-init] No custom files found, skipping…" … „[ls.io-init] done." No error at
|
||||
all. It was merely marked `unhealthy`, i.e. its healthcheck was not passing — which is enough for
|
||||
traefik to refuse it a route, but is NOT corruption. Dropping its image was probably unnecessary.
|
||||
* **gokapi** — **no log output whatsoever**, and `Restarting (0)`: it exits cleanly and instantly.
|
||||
That is a configuration/first-run shape, not a corrupt binary.
|
||||
* **immich-server** — `file: 'auth.c', line: '331', routine: 'auth_failed'` under Node.js. That is
|
||||
**PostgreSQL refusing the password**, not a broken library.
|
||||
|
||||
### The likely real cause, and it is mine: regenerated secrets over existing databases
|
||||
My sequential re-seed called `gen` again for every app, so each one was deployed with **freshly
|
||||
generated DB passwords** — while the database volumes created during the first (failed, parallel)
|
||||
burst still hold databases initialised with the FIRST passwords. Postgres/MariaDB keep the password
|
||||
from `POSTGRES_PASSWORD`/`MYSQL_PASSWORD` at volume-init time and ignore it afterwards, so the app
|
||||
then authenticates with a password the database has never heard of. `auth_failed` is exactly that.
|
||||
|
||||
**Consequence:** re-pulling an image cannot fix this, and neither can restarting. The apps whose
|
||||
volumes predate the re-seed need a clean removal (with their data) and a fresh deploy — which costs
|
||||
nothing here because none of them holds real household data yet.
|
||||
|
||||
**Not a product defect.** The product deployed exactly what I asked it to deploy, twice, with the
|
||||
values I supplied each time.
|
||||
|
||||
## CORRECTION — „nextcloud is repaired" was WRONG, and the container badge is why I believed it
|
||||
I wrote that the image re-pull repaired nextcloud, on the strength of `Up (healthy)`. Checking the
|
||||
log with timestamps against the guest's own clock:
|
||||
|
||||
guest time now 2026-09-16T21:16:02Z
|
||||
2026-09-16T21:14:09Z „Access denied for user 'nextcloud'@'172.21.0.4' (using password: YES)"
|
||||
2026-09-16T21:14:19Z „Error while trying to create admin account: … Access denied for user
|
||||
'nextcloud'@'172.21.0.4' (using password: YES)"
|
||||
|
||||
Two minutes old — **current, not leftovers from the crash-looping period.** The re-pull did fix the
|
||||
corrupt library (the app now starts instead of exiting 127), but the SECOND fault is still there: the
|
||||
database was initialised with the first deploy's password and the app now presents the re-seed's new
|
||||
one. It could not even create its admin account.
|
||||
|
||||
**And the container says `healthy` the whole time.** The healthcheck is the app image's own — Apache
|
||||
answers, so the probe passes — while the application cannot reach its database at all. This is the
|
||||
project's standing lesson in another costume: **a health signal is not a data signal**, and „healthy"
|
||||
answered a different question from the one I was asking.
|
||||
|
||||
So nextcloud joins gokapi and paperless in the clean remove-and-redeploy. Retracted here rather than
|
||||
left standing, because the wrong version of this paragraph was already written two entries above.
|
||||
|
||||
## An HTTP 000 is „no answer", not „it failed" — and the action still happened
|
||||
The immich repair's start call returned:
|
||||
start -> 000
|
||||
`000` is curl's code for „no response received", not a refusal by the server. Twenty seconds later:
|
||||
immich-server Up 4 seconds (health: starting)
|
||||
So the start DID take effect; only the answer was lost (the controller was busy stopping/starting
|
||||
several stacks at once). Recorded because reading `000` as „the start failed" would have led me to
|
||||
issue a second start on an app that was already coming up.
|
||||
|
||||
## Household state at 21:17Z, and the decision to move round 2
|
||||
immich-server Up 4 seconds (health: starting) — DB password mismatch still expected
|
||||
gokapi Restarting (1) — clean remove+redeploy in progress
|
||||
bookstack Up about a minute (**unhealthy**) — healthcheck not passing
|
||||
nextcloud Up about a minute (healthy) — but DB-broken, see the correction above
|
||||
paperless-webserver Up 8 seconds — clean remove+redeploy in progress
|
||||
(the other seven apps: up and serving)
|
||||
|
||||
**Decision: round 2 moves to ~23:45 CEST.** Five of twelve apps are mid-repair from damage I caused,
|
||||
and a chaos round measures nothing if the household is already broken before the accident lands. The
|
||||
SCHEDULE is unchanged — same actions, same apps, same accidents, same order, drawn from the seed
|
||||
before anything ran; only the wall clock moves, and the 05:00 stop is unchanged. At ~25-minute
|
||||
spacing a 23:45 start still reaches round 12 by about 04:20.
|
||||
|
||||
The queue behind the current job: **nextcloud, immich and bookstack** get the same clean
|
||||
remove-and-redeploy. They are done one at a time, never two repair jobs at once on the same box —
|
||||
concurrent stop/start on one controller is what produced half of tonight's confusion already.
|
||||
|
||||
@@ -15,3 +15,52 @@
|
||||
2026-09-16T21:09:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:09:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:10:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:10:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:10:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:11:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
|
||||
## ROUND 1 — the five things
|
||||
**action:** `offsite-run` (drawn app: adventurelog — an off-site run is a TIER action; the whole
|
||||
repository is one run, so the named app is which row is read afterwards)
|
||||
**accident:** none — round 1 is a control round by the schedule's own constraint 5
|
||||
|
||||
1. **What the customer saw.** „A távoli mentés elindult — az állapot itt frissül." then, at the end,
|
||||
the repository reported ORPHANED: „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). Új mentés a tároló visszaállít…"
|
||||
2. **What the box did by itself.** Walked all twelve apps — stop, dump each volume with real byte
|
||||
counts, restart („Stopping X for safe volume dump" / „Restarting X after volume dump") — captured
|
||||
eleven, could not capture the one that was crash-looping, and finished.
|
||||
3. **Time to steady.** `last_duration` **1m45s**, `last_run` 2026-09-16T21:09:00Z, `progress.active`
|
||||
back to false, `last_error` empty. The box never left steady: this was a control round.
|
||||
4. **Alarms that fired, and were they true.** Three, all TRUE:
|
||||
`app_start_failed` (warning) named Nextcloud; `backup_run_failures` (error) said „1 of 12 apps
|
||||
failed to back up in this nightly run: nextcloud"; `offbox_repo_orphaned` (warning) reported the
|
||||
orphaned repository. The status endpoint agrees with the alarm: `"orphaned": true`.
|
||||
5. **Alarms that should have fired and did not.** None. Everything that happened was announced, and
|
||||
nothing was announced that had not happened.
|
||||
|
||||
**Household loop in this window:** 3 lines marked FAILED — **all three are MY error**, not the box's:
|
||||
the loop counted the dashboard's `http=301` redirect as a failure while counting the same 301 as OK
|
||||
for app reads. Fixed at 21:12Z and marked in the log; only lines after that marker are scored.
|
||||
|
||||
**Round 1's verdict:** the off-site tier is armed (escrowed) and runs, but on THIS box — a rebuild for
|
||||
an existing customer — the remote repository belongs to a key the box no longer has, so no snapshot
|
||||
was written. That is the documented rebuild behaviour, surfaced honestly with the route out named.
|
||||
2026-09-16T21:11:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:11:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:12:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:12:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:12:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:13:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:13:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:13:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:14:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:14:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:14:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:15:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:15:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:15:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:16:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:16:35Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:16:55Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
2026-09-16T21:17:15Z {"last_duration":"1m45s","last_error":"","last_run":"2026-09-16T21:09:00Z","orphaned":true,"progress":{"active":false,"current_app":"","percent":0,"bytes_done":0,"total_bytes":0,"done_human":"","total_human":"","files_done":0,"total_files":
|
||||
|
||||
Reference in New Issue
Block a user