4978d355b8
Endpoint-level supervised run against snapshot 49e7cb46, the same one that aborted in round 2. Controller log shows stop -> 'Starting stack immich services only: [immich-postgres]' -> replay rc-0 in 20s -> full start. No 'already exists'. Operation reported success (round 2: failure). immich's own DatabaseService logged 'No schema drift detected' twice, where round 2 left it reporting drift. 11 assets active, 4/4 containers healthy, 231 public indexes. Credentials were supplied file-to-file, never echoed, and shredded with both cookie jars at the end of the run.
182 lines
12 KiB
Markdown
182 lines
12 KiB
Markdown
# 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 A–G
|
||
|
||
| 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.
|
||
|
||
## 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 (golden 0.153.0):** probes P1–P3 first. **P3 is load-bearing** — the drill environment is
|
||
at the vacation site and must be proven able to pull
|
||
`gitea.dooplex.hu/admin/felhom-controller:0.153.0` BEFORE any bake. If unreachable: stop and
|
||
report; change no routing/DNS/nft.
|
||
- **STOP-2 (Viktor, password-gated):** Day-0 manifest Golden → 0.153.0 (Agent 0.90.1 / MinAgent
|
||
0.90.0 unchanged — the CHANGELOG's no-coupling declaration is the authority), then floor →
|
||
v0.153.0 saved **LAST**. Watching the demo box wake during the manifest save banks the **R-23(a)**
|
||
operator-UI save→apply evidence — log the timestamps if observed.
|
||
- **Viktor's C6 customer-restore UI run** (note the empty-the-trash method).
|
||
|
||
## 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.
|