Files
felhom-controller/REPORT.md
T
admin 8d33a90888 docs: STOP-2 done, 9100 destroyed — and a correction
STOP-2 applied by the operator in the right order: Day-0 Golden -> 0.153.0
(sha256 matches the bake), Agent/MinAgent 0.90.0 unchanged, global floor ->
v0.153.0 saved last. Build guest 9100 destroyed.

Agent 0.90.1's absence from the hub dropdown is CORRECT, not a defect: it
was never published (Gitea 404; 0.90.0 returns 206) and felhom-pve runs
0.90.0. The v0.90.1 source is committed at 9596d5a, so R-39 is a
build+publish away.

CORRECTION: my earlier claim that the stored controller password was stale
was WRONG. Values in ~/.config/credentials are single-quoted and my cut
extraction kept the quotes, sending a 15-char string instead of the 13-char
password. Re-tested stripped: 302 + session. The credential was always
correct.

Also records honestly that the reconstitute restored over an already-good
state, so C6 still needs the destructive empty-the-trash drill.
2026-07-20 19:07:06 +02:00

264 lines
18 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# REPORT — R-47: the DB replay must not race the app (both restore paths) · felhom-controller v0.153.0
**Date:** 2026-07-20 · **Repo:** `felhom-controller` (v0.152.0 → **v0.153.0**) · Trunk, pushed to
`main`. · **Baseline:** `main` @ `fd40b29` (clean, equal to `origin/main` at session start)
---
## 1. What was wrong
`felhom.eu/documentation/audits/DIAG-immich-restore-round2-2026-07-19.md`, finding **H4**. The
offsite reconstitution ran its designed sequence — safety dump → stop → start → replay — and the
replay aborted:
```
10:58:25 controller: replaying DB dump into immich-postgres
10:58:33 immich-server: "Reindexing clip_index" -> "Reindexed clip_index"
10:58:35 controller: ERROR relation "clip_index" already exists - exit status 3
```
`ImportDump` needs a running database container, so the code started the WHOLE stack first. That gave
the application an eight-second window to rebuild the very schema objects the dump was about to
create; under `ON_ERROR_STOP=1` the collision aborted the script. The data survived only because
`pg_dump` emits COPY before CREATE INDEX — a collision earlier in the script would have left a
genuinely half-restored database and reported it identically.
**Class defect.** The local `RestoreFromRecoveryUnit` had the same start-then-replay shape, hidden
inside `RecreateStackFromUnit` (which ended in a full `compose up -d`). Both are fixed here.
## 2. What was built
**Part 1 — the seams**
| Change | File |
|---|---|
| `dbTypeForImage` extracted from `DiscoverDatabases` (behaviour byte-equivalent) and shared | `internal/appbackup/dbdump.go`, `internal/appbackup/dbservices.go` (new) |
| `DBServiceNames(composePath)` — sorted compose SERVICE names holding a DB; yaml.v3 `services:` map parse | `internal/appbackup/dbservices.go` (new) |
| `Manager.StartStackServices(name, services)` — scoped `up -d`, **refuses an empty list** | `internal/stacks/manager.go` |
| `RedeployFromEnv` split; persist half is `PersistUnitRedeployConfig` (starts nothing) | `internal/stacks/deploy.go` |
| `StackDataProvider`: `RecreateStackFromUnit``RecreateStackDefinitionFromUnit` (+ `StartStackServices`) | `internal/appbackup/appdata.go` |
| Adapter: definition-only recreate + delegation | `cmd/controller/main.go` |
| `DBServiceNames` forwarder | `internal/backup/appbackup_bridge.go` |
**Part 2 — offsite** (`internal/backup/offbox_reconstitute.go`): DB services resolved from the LIVE
compose before any mutation; fail-closed refusal when a DB exists but no service is identifiable;
sequence is now **stop → files → `StartStackServices(dbServices)` → replay → `StartStack` (full) →
health wait**; both failure exits from the window do a best-effort full start.
**Part 3 — local** (`internal/backup/restore_unit.go`): DB services resolved from the UNIT's compose
(it is about to become the live one) plus `hasReplayableDump` (excludes `pre-restore-` safety dumps);
same fail-closed gate before the first mutation; sequence is now **stop → volumes →
`RecreateStackDefinitionFromUnit``StartStackServices` → replay → `StartStack` (full) → health
wait**, with the pre-existing `dataErr` / "completed with data errors" semantics preserved.
Untouched, as specified: `restore_db.go`, `ImportDump`, `waitDBReady`, the dump flags
(`--clean --if-exists`, `ON_ERROR_STOP=1`), `mapOffsiteRestorePaths`, the copiers, the honesty
surfaces, `IsDownState`/alerting (R-51), and the agent/hub.
## 3. Tests — 19 new, Groups AG
| Group | Test | Result |
|---|---|---|
| A | `TestReconstituteReplaysWithOnlyTheDBServiceUp` — order **plus state-at-replay-time** | PASS |
| A | `TestReconstituteReplaysDBAndOrdersOperations` (existing, sequence assertion updated) | PASS |
| B | `TestReconstituteNoDBAppNeverStartsServicesOnly` — negative, zero scoped starts | PASS |
| C | `TestReconstituteRefusesWhenNoDBServiceIdentifiable` — zero-mutation effect | PASS |
| C | `TestRestoreFromUnitRefusesWhenNoDBServiceIdentifiable` — zero-mutation effect | PASS |
| D | `TestRestoreFromUnitReplaysWithOnlyTheDBServiceUp` | PASS |
| D | `TestRestoreFromUnitNoDumpsTakesOneFullStart` | PASS |
| D | `TestRestoreFromUnitIgnoresSafetyDumpsWhenDecidingToReplay` | PASS |
| E | `TestReconstituteReplayFailureStillBringsTheStackUp` | PASS |
| E | `TestReconstituteDBOnlyStartFailureStillBringsTheStackUp` | PASS |
| E | `TestRestoreFromUnitReplayFailureStillBringsTheStackUp` | PASS |
| F | `TestDBTypeForImage`, `TestDBServiceNames` (8 sub-cases), `TestDBServiceNames_TopLevelKeysAreNotServices`, `TestDBServiceNames_UnreadableAndUnparseableError`, `TestDiscoverAndComposeAgreeOnTheSameImages` | PASS |
| G | `TestStartStackServicesRefusesEmptyList`, `TestPersistUnitRedeployConfigPersistsWithoutStarting`, `TestPersistUnitRedeployConfigRejectsUnknownStack` | PASS |
The core assertion is deliberately not "no error": a recording provider captures whether the FULL
stack had been started at the moment the import fired. Asserting only `err == nil` passes on the
pre-fix shape — which is exactly how this shipped.
The compose-parser decoys use the catalog's REAL immich template shape (`immich_ml_cache:`,
`immich_postgres_data:` as top-level `volumes:` keys, `ghcr.io/immich-app/postgres:16-vectorchord…`
as the pin) — the exact input a line scan would misread.
### Companion red-proofs — three run, all reverted, tree clean
| # | Pre-fix shape restored | Failure observed |
|---|---|---|
| 1 | offsite: `StartStackServices` → full `StartStack` before the replay | `TestReconstituteReplaysWithOnlyTheDBServiceUp`: *"the database service was NOT started before the replay"*; `TestReconstituteReplaysDBAndOrdersOperations`: sequence `"stop,start,start"` |
| 2 | local: full `StartStack` inserted before the replay | `TestRestoreFromUnitReplaysWithOnlyTheDBServiceUp`: *"the FULL stack was already up when the replay fired — the H4 race, on the local path"* |
| 3 | both fail-closed gates deleted | both `RefusesWhenNoDBServiceIdentifiable` tests: *"expected a refusal…"* |
### Green gate
`go build ./... && go vet ./... && go test ./...`**23/23 packages green**, exit 0
(`internal/backup` 174 s). New tests by package: backup +11, appbackup +5, stacks +3.
## 4. Deployment
Built + pushed from the clean tree at `78ff991`: `gitea.dooplex.hu/admin/felhom-controller:0.153.0`,
digest `sha256:cc02c950c47456dac01aa754f23befbdfb3d4897b0a9863aafa3589cff95b8ab`. Deployed to guest
9201 via the bootstrap path (pull → `/etc/felhom-controller-image` → restart bootstrap service).
Verified: `gitea.dooplex.hu/admin/felhom-controller:0.153.0 | Up (healthy)`, clean startup, and
`Event pushed: controller_started (info) — Controller elindult (0.153.0)`.
## 4b. STOP-1 — supervised live leg: **PASSED** (2026-07-20, operator present)
Method: **endpoint-level** — the exact endpoints the UI posts to, driven with an authenticated
session inside the guest (no browser on DooPlex; no state hand-setting, no `docker exec` shortcut
around the pipeline). App: **immich** (a real DB-indexed app), snapshot `49e7cb46` — the SAME
snapshot that aborted in round 2.
Baseline before the run: **11 assets, all `active`**.
1. `POST /backup/offbox/restore` `app=immich mode=full confirm=1` → 302; scratch staged
**15:30:08 UTC**: `restored immich (49e7cb46, full=true) → …/backups/offsite-restore/immich`.
2. `POST /backup/offbox/reconstitute` `app=immich confirm=1` → 302, fired **15:39:36 UTC**.
**Controller log — the ordering, live:**
```
15:39:42 [offbox] immich: pre-restore safety dump written -> pre-restore-20260720T153941Z-immich-postgres.sql (49.9 MB)
15:39:42 [stacks] Stopping stack: immich
15:39:43 [stacks] Starting stack immich services only: [immich-postgres] <- THE FIX
15:39:43 [backup] Restore immich: replaying DB dump into immich-postgres (postgres)
15:40:03 [backup] Restore immich: replayed 1 DB dump(s) <- rc-0, 20 s
15:40:03 [stacks] Starting stack: immich <- full start, only now
15:40:27 [offbox] reconstituted immich from snapshot 49e7cb46: 6 file(s) placed,
1 DB dump(s) replayed, safety dump=pre-restore-…, skewed=false
```
**Verification through the system's own surfaces:**
| Check | Round 2 (v0.148.0) | This run (v0.153.0) |
|---|---|---|
| `already exists` / replay abort | `ERROR relation "clip_index" already exists` (exit 3) | **none** — replay exited 0 |
| App up during replay | yes (immich-server rebuilt `clip_index` mid-replay) | **no** — only `immich-postgres` was up |
| Operation outcome | reported FAILURE | **success**, `dbs=1` |
| immich's own schema verdict | **schema drift** reported | **`No schema drift detected`** — twice (Microservices + Api) |
| Assets | 11 (recovered by luck of `pg_dump` ordering) | **11, all `active`** |
| Containers | — | all four immich containers `Up (healthy)` |
| `public` indexes | incomplete (aborted script) | **231** |
The decisive line is `Starting stack immich services only: [immich-postgres]` followed by a replay
that exits 0 — the window in which H4 occurred no longer exists. The DB service name was resolved
from the LIVE compose by `DBServiceNames`, unassisted.
Credentials handling per GL-1: the operator's password was supplied file→file, never echoed, and the
file plus both cookie jars (host and guest) were shredded at the end of the run.
## 4c. Phase C — golden **0.153.0** baked and published (2026-07-20)
Probes first, all before any mutation:
| Probe | Result |
|---|---|
| **P1** — read `180:/mnt/5_hdd/felhom.eu/drill/bake-0.146.0.log` end to end | recipe extracted: `pct`-based LXC 9100 on felhom-pve, args `9100 <template> local-lvm local vmbr0 <controller-image>`, creds via `REGISTRY_USER`/`REGISTRY_TOKEN`, publish to the gitea generic package registry |
| **P2** — build environment matches the log's starting point | 9100 absent (clean slate ✓); local-lvm 277 G / local 80 G free ✓; **DEVIATION: the Debian 13 template cache was EMPTY** (the 0.146.0 bake had it cached) |
| **P3** — registry reachable from the vacation site (**load-bearing**) | **PASS.** `gitea.dooplex.hu``37.191.56.193` (public path); registry `/v2/` → 401 (alive, auth-gated); gitea API → 200; Docker Hub `/v2/` → 401. Independently corroborated: guest 9201 pulled `felhom-controller:0.153.0` from that registry the same afternoon |
**P2 deviation, handled explicitly:** `pveam download local debian-13-standard_13.6-1_amd64.tar.zst`
(129 954 319 B, checksum verified, 22 MB/s). This is the ONE departure from the 0.146.0 recipe and
it is environmental, not a build-golden defect. Operator approved before it ran.
Bake: `build-golden.sh` **v2.1.0** (confirmed on the host copy), run **detached under `setsid`+`nohup`**
so an SSH blip over the tailnet could not orphan a half-built guest. Controller image
`gitea.dooplex.hu/admin/felhom-controller:0.153.0`.
### Gate table — vs the 0.146.0 row
| Gate | 0.146.0 | **0.153.0** |
|---|---|---|
| Script version | v2.0.0 | **v2.1.0** |
| Docker in build guest | overlay2, separate `/var/lib/docker` + `/mnt/sys_drive` mounts | same ✓ |
| Controller image baked | 0.146.0 | **0.153.0** ✓ |
| **Infra images baked** | **3** (historical fallback list) | **4**`traefik:v3.6.7`, `cloudflare/cloudflared:2026.6.0`, `gtstef/filebrowser:1.3.3-stable`, **`gitea.dooplex.hu/admin/felhom-samba:1.1.0`** ✓ |
| Source of the infra list | hard-coded fallback | **`--print-infra-images` from the 0.153.0 binary itself** — no WARN line in the log, so the fallback never fired |
| `docker image ls` inside the guest ⊇ that list | — | **verified** — all four present, plus the baked controller |
| Archive | 584 MB | **618 MB**, volid `local:backup/vzdump-lxc-9100-2026_07_20-17_50_57.tar.zst` |
| Publish: pre-delete | HTTP 404 | **HTTP 404** ✓ |
| Publish: upload | HTTP 201 | **HTTP 201** ✓ |
| Anonymous GET + byte-match | — | **HTTP 200, 648 549 366 B, sha256 matches exactly** ✓ |
| Ranged request (resumable restore) | — | **HTTP 206**, 1024 B ✓ |
| Hub can fetch it from its own network position | — | **verified**`wget` from the `hub-…` pod exits 0 |
```
GOLDEN_VERSION=0.153.0
GOLDEN_SHA256=15fdd191f3c660a60dc8651111053dd84281aeebc6c4c0f9ecdd3a87cb45a9d0
```
**GL-1 teardown:** the token was written to a `0600` env file via STDIN (never in argv on either
host), sourced by the detached run, and **shredded**. Token-leak grep over the bake transcript
(host copy and the retained copy) = **0**; the build guest holds no registry credential; build guest
9100 left **stopped** (destroy with `pct destroy 9100 --purge`); the 618 MB local verification copy
was deleted. Log retained beside its predecessor: `180:/mnt/5_hdd/felhom.eu/drill/bake-0.153.0.log`.
**Honest scope note:** I verified the golden artifact is published, byte-correct and fetchable *by
the hub*. I did **not** render the hub's golden **dropdown** — that is the password-gated operator
UI, and it remains part of STOP-2.
## 4d. STOP-2 — hub saves: **DONE** (operator, 2026-07-20)
Both password-gated saves applied in the correct order and confirmed by screenshot:
| Setting | Value |
|---|---|
| Day-0 artifact — Golden | **0.153.0**, sha256 `15fdd191f3c660a60dc8651111053dd84281aeebc6c4c0f9ecdd3a87cb45a9d0` (matches the bake exactly) |
| Day-0 artifact — Agent | 0.90.0 (unchanged) |
| Min agent | 0.90.0 (unchanged — v0.153.0 declares no coupling) |
| Managed-updates global floor | **v0.153.0**, source `DB (hub_settings)`, saved **last** ✓ |
**Agent 0.90.1 is absent from the dropdown — correct, not a defect.** It was built on the old
Windows workstation but **never published**: `felhom-agent/0.90.1` in Gitea returns **404** (0.90.0
returns 206), and felhom-pve reports `felhom-agent 0.90.0`. The hub lists only published versions.
The v0.90.1 source IS committed (`9596d5a`, the R-39 `pvesm set --server` hotfix), so shipping it is
a build+publish away — tracked under R-39, out of scope here.
Build guest **9100 destroyed** (`pct destroy 9100 --purge`, all three LVs removed); only 9201
remains on the host.
## 5. NOT yet live-validated — remaining human/supervised work
- ~~**STOP-1**~~ — **DONE 2026-07-20, PASSED.** See §4b for the log ordering, timestamps and the
before/after comparison against round 2. Residual: the immich **timeline screenshot** still cannot
be captured from here (no browser on DooPlex) — that one visual remains the operator's.
- ~~**Phase C**~~ — **DONE 2026-07-20.** Golden 0.153.0 baked, published, all gates green
(§4c). `GOLDEN_SHA256=15fdd191f3c660a60dc8651111053dd84281aeebc6c4c0f9ecdd3a87cb45a9d0`.
Housekeeping left for whoever is next at the host: `pct destroy 9100 --purge`.
- ~~**STOP-2**~~ — **DONE** (§4d). Golden 0.153.0 + floor v0.153.0 saved in the right order.
- **Viktor's C6 customer-restore UI run — STILL OUTSTANDING, and it is the one that matters.**
The 2026-07-20 reconstitute restored over an ALREADY-GOOD state (11 assets before, 11 after): it
proves the H4 window is closed and the operation is clean and non-destructive, but **nothing was
ever lost in it**. C6 needs the destructive shape — delete photos, **empty the trash** (deleting in
an app's own UI usually means trash, and a drill written that way merges 0 files, flashes success
and proves nothing), then restore and verify the app's *content*, not the file count.
- **The R-23(a) operator-UI save→apply evidence** was not captured: nobody was watching the demo box
wake during the manifest save. Cheap to bank on the next manifest save.
## 6. Observations (out of scope, recorded not acted on)
- **The `pre-restore-` prefix is load-bearing in three separate places** (the replay's exact-name
match, `OffsiteScratchPair`'s dump sniff, and now `hasReplayableDump`) with no shared predicate
deciding "is this file a replay source". A fourth consumer that forgets the exclusion would arm the
DB-only window for an app that has nothing to replay. Worth a single helper at some point.
- **`reimportDBDumpsFrom`'s own `hasDump` scan does NOT exclude the safety prefix** (unchanged here —
`restore_db.go` was explicitly out of scope). Harmless today because the per-DB lookup is an exact
`<stack>-<dbtype>.sql` match, so a directory holding only safety dumps merely produces the
"no matching running DB container" WARN instead of a clean zero.
- **`dbTypeForImage` maps both `mysql` and `mariadb` to `DBTypeMariaDB`.** Pre-existing and correct
for the current catalog (the `mariadb` client speaks to both), but it is an assumption, not an
invariant, and it is now written down in one place instead of two.
- **`RedeployFromEnv` has no end-to-end test** (it shells out to compose), so the split's equivalence
is asserted on the persist half only. That is the half the split could break; the tail is
byte-identical code that was moved, not rewritten.
- **R-29a (`estimate.go` gate finding)** remains open and was not touched.
- **CORRECTION to an earlier claim in this session.** Mid-run I reported that the controller password
in `180:~/.config/credentials` was **stale** and had been superseded by the customer-claim flow.
**That was wrong.** The values in that file are single-quoted (`PASSWORD='…'`) and my
`cut -d= -f2-` extraction kept the quotes, so a 15-character string with literal `'` on both ends
was sent instead of the 13-character password. Re-tested with the quotes stripped: `302` + session
cookie. The credential was correct the entire time; no rotation, no drift, nothing to reconcile.
The lesson recorded in memory is the general one: **an auth failure is evidence about the bytes you
sent, not proof about the stored secret** — a 2-character length discrepancy is this bug's
signature, and it was stated confidently three times before being caught.