docs: DIAG round 2 — H1 confirmed, H4 found; two standing rulings landed
VERDICT. H1 confirmed: the reconstitution never ran. /backup/offbox/reconstitute
was never hit (reconstituted/safety-dump/replay line counts all 0); the operator
clicked the old missing-only button, which merged 34 files and left the DB
untouched. H2 rejected (the full path never executed; staging used the correct
snapshot 49e7cb46). H3 rejected (no replay happened; DB was genuinely asset:0).
R-44 is exonerated and working: 49e7cb46 carries offsite_run_id 20260719T102851Z
and its dump probes to asset:11 / user:1 — a properly coherent pair, against
round 1's asset:0 / user:0.
H4 (NEW, the more important result). Phase-3 recovery ran the real sequence and
the v0.148.0 path executed correctly — safety dump, stop, start, replay — then
the replay ABORTED: relation "clip_index" already exists. Proven to the second:
10:58:25 controller begins replay
10:58:33 immich-server "Reindexing clip_index" -> "Reindexed clip_index"
10:58:35 dump's CREATE INDEX clip_index fails, exit 3
The replay races the app's own schema repair, because reconstitution starts the
stack before replaying (ImportDump needs a live container). The photos survived
only because pg_dump emits COPY data before CREATE INDEX — luck, not design. The
same start-then-replay shape is on the LOCAL path, so it is a class defect.
Recovery: PARTIAL and STOPPED as instructed. All 11 assets are back and visible
by every DB criterion (status=active, deletedAt null, all files resolve), but the
operation reported failure and immich reports schema drift. Not clean acceptance
evidence; no second attempt made; safety dump read only.
Findings -> R-47 (the replay race), R-48 (restore controls separable only by
layout — the proven cause of this incident), R-49 (1.1 GB of a 1.2 GB immich
backup is ML model cache + a postgres data-dir tar duplicating the .sql dump +
immich's own nightly dump; recorded, not changed).
RULINGS LANDED.
- 00-capability-map.md:61 -> PARTIAL, scope-corrected: 6D's destruction hit the
FILE TREE only; the DB survived in its named volume, so "end-to-end from
offsite alone" overclaimed scope.
- The 704.6 MiB "discrepancy" -> CLOSED, not a defect: it was immich's own
Tarhely widget, never a controller page. Same for round 2's 650MiB->1.4GiB.
- customer-restore row: partial evidence recorded, NOT flipped.
Diagnosis only — no code, label or layout changes; no forget/prune.
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01P9Nn14TWGzKoqAJAiVwC2s
This commit is contained in:
@@ -174,12 +174,16 @@ run. So on a normal box the offsite dump is never even staged to disk. Correct a
|
||||
15 MB, mtime 07-18 17:10, stranded by the immich 2→3 redeploy. The live DB has never known about
|
||||
it. Dead weight, not today's issue; worth a sweep policy for major redeploys.
|
||||
|
||||
### 6. [LOW, unresolved] Storage figure discrepancy
|
||||
### 6. [CLOSED — not a defect] Storage figure discrepancy
|
||||
|
||||
The brief cites **704.6 MiB** used on the library storage. Measured: **126 MB** total
|
||||
(`upload` 72 M, `encoded-video` 30 M, `backups` 18 M, `thumbs` 8 M). Not reconciled in this
|
||||
session. If 704.6 MiB came off a controller Storage page, that gap is its own defect and needs a
|
||||
separate look.
|
||||
(`upload` 72 M, `encoded-video` 30 M, `backups` 18 M, `thumbs` 8 M).
|
||||
|
||||
**RULED 2026-07-19 (Viktor): resolved, no controller defect.** The 704.6 MiB came from **immich's
|
||||
own Tárhely widget** — immich-internal accounting — not from any controller Storage page. The two
|
||||
numbers measure different things and were never expected to agree. The same explanation covers the
|
||||
„650 MiB → 1.4 GiB" figure quoted during round 2, which likewise does not match the controller's
|
||||
measurement of the tree. Closed; no follow-up item.
|
||||
|
||||
### 7. [Method] A UI delete cannot test restore
|
||||
|
||||
|
||||
@@ -0,0 +1,231 @@
|
||||
# DIAGNOSE — v0.148.0 full-restore acceptance: files back, timeline empty (round 2, 2026-07-19)
|
||||
|
||||
> **Class:** diagnosis. No product code changed. **Access mode: SSH** (the box was reachable from
|
||||
> the workstation; every step below is direct evidence, none inferred).
|
||||
> **Companion:** `DIAG-immich-restore-2026-07-19.md` (round 1, which produced R-43 + R-44).
|
||||
|
||||
---
|
||||
|
||||
## TL;DR
|
||||
|
||||
**H1 confirmed: the reconstitution never ran.** The operator clicked the old missing-only button;
|
||||
`/backup/offbox/reconstitute` was **never hit** (`reconstituted lines: 0`, `safety dump lines: 0`,
|
||||
`replay lines: 0`). Files came back (34 merged — hence the disk growth), the database did not.
|
||||
|
||||
**Then Phase-3 recovery found a NEW defect (H4), which is the more important result.** Running the
|
||||
real sequence deliberately, the v0.148.0 path executed correctly — safety dump → stop → start →
|
||||
replay — and the **replay aborted**: `ERROR: relation "clip_index" already exists`.
|
||||
|
||||
Root cause, proven to the second: **the replay races the application's own schema repair.** The
|
||||
reconstitution starts the stack *before* replaying (ImportDump needs a live container), which gives
|
||||
immich-server a window to recreate schema objects the dump is about to create.
|
||||
|
||||
```
|
||||
10:58:25 controller: replaying DB dump into immich-postgres
|
||||
10:58:33 immich-server: "Reindexing clip_index" → "Reindexed clip_index" ← app recreates it
|
||||
10:58:35 controller: ERROR relation "clip_index" already exists — exit status 3
|
||||
```
|
||||
|
||||
**The photos ARE back** (11 assets, `status=active`, `deletedAt` null, all 11 files resolve, owned
|
||||
by the live user) — because `pg_dump` emits COPY data *before* CREATE INDEX, so the abort landed
|
||||
after the data. **That success is accidental.** A collision earlier in the script would abort before
|
||||
the data and leave a genuinely half-restored database, reported identically.
|
||||
|
||||
**This is NOT clean §9 acceptance evidence.** The run reported failure, and immich now reports
|
||||
schema drift (indexes the aborted script never created). Recovery is PARTIAL.
|
||||
|
||||
---
|
||||
|
||||
## Phase 1 — facts
|
||||
|
||||
### 1. Endpoint timeline (controller log, guest UTC)
|
||||
|
||||
| UTC | Event |
|
||||
|---|---|
|
||||
| 10:23:13 | controller 0.148.0 starts |
|
||||
| 10:28:51 | manual offsite run starts — **v0.148 dump pre-phase runs** |
|
||||
| 10:29:56 | `pre-push dump leg completed in 1m5.04s — snapshot pair is coherent` |
|
||||
| 10:32:52 | `backed up immich (1 mandatory path(s))` |
|
||||
| 10:33:41 | `backup OK: 3 app(s), 6 snapshot(s), 4m45s` |
|
||||
| 10:38:32 | `restored immich (49e7cb46, full=true) → …/backups/offsite-restore/immich` (staging) |
|
||||
| **10:39:55** | **`placed immich from offsite scratch: 34 file(s) merged (missing-only)`** |
|
||||
|
||||
Counted over the same window: `reconstituted: 0 · safety dump: 0 · replaying DB dump: 0 ·
|
||||
missing-only: 1`. The reconstitute endpoint appears nowhere in the log. **H1.**
|
||||
|
||||
### 2. Which snapshot / which dump
|
||||
|
||||
Only two snapshots exist for immich:
|
||||
|
||||
- `6df12205` — 2026-07-18T17:13:46Z
|
||||
- `49e7cb46` — 2026-07-19T10:30:01Z ← staged, correct
|
||||
|
||||
**No snapshot was pushed after the deletion**, so there is no post-delete empty-state snapshot to
|
||||
restore by accident. `49e7cb46`'s unit carries `offsite_run_id: 20260719T102851Z` /
|
||||
`dumps_at: 2026-07-19T10:28:51Z`, and its dump (`immich-postgres.sql`, mtime 10:28:52, 52 393 708 B)
|
||||
probes to **`asset: 11` / `user: 1`**.
|
||||
|
||||
> **R-44 is working exactly as designed.** Round 1's dump was `asset: 0 / user: 0`. This one holds
|
||||
> the customer's data and is stamped as coherent with the files beside it. The pair mechanism is
|
||||
> not implicated in this failure.
|
||||
|
||||
The `pre-restore-` safety dump exists: `pre-restore-20260719T105811Z-immich-postgres.sql`,
|
||||
51 964 807 B, 10:58:11 — written before anything was stopped or overwritten, as designed.
|
||||
|
||||
### 3. DB truth
|
||||
|
||||
Before Phase 3: `total 0 / trashed 0 / live 0`, 1 user — the trash was genuinely emptied, this was
|
||||
real data loss (unlike round 1, where the rows survived as trashed).
|
||||
|
||||
After Phase 3: **`asset: 11, all status=active, deletedAt null, isOffline false, all 11 owned by
|
||||
the live user`**; all 11 `originalPath` values resolve to files on disk. Every timeline-visibility
|
||||
condition is satisfied.
|
||||
|
||||
### 4. File truth — what the 1.2 GB actually is
|
||||
|
||||
The operator's suspicion (immich's own DB-backup feature accumulating) is a **minor** contributor:
|
||||
one 18 MB file. The dominant item is something else entirely.
|
||||
|
||||
| Item | Bytes | Share |
|
||||
|---|---:|---:|
|
||||
| `volume-dumps/immich_immich_ml_cache.tar` | 823 660 032 | **~60%** |
|
||||
| `volume-dumps/immich_immich_postgres_data.tar` | 308 251 136 | ~23% |
|
||||
| `db-dumps/immich-postgres.sql` | 52 393 708 | ~4% |
|
||||
| `volume-dumps/immich_immich_redis_data.tar` | 6 358 016 | <1% |
|
||||
| `appdata/immich` tree (below) | ~127 MB | ~10% |
|
||||
| — of which `upload/` (originals, 2 user trees) | 72 MB | |
|
||||
| — of which `encoded-video/` | 30 MB | |
|
||||
| — of which `backups/` (immich's OWN nightly dump) | 18 MB | |
|
||||
| — of which `thumbs/` | 8 MB | |
|
||||
|
||||
**The single biggest thing in the customer's offsite backup is immich's machine-learning model
|
||||
cache — 786 MiB of re-downloadable model weights.** Second is a raw tar of the postgres data
|
||||
directory, which duplicates the logical `.sql` dump captured beside it (both are in every
|
||||
snapshot). Actual irreplaceable customer content — the originals — is 72 MB, and even that includes
|
||||
the ~36 MB stranded pre-v3 user tree (`dccc13fe…`) from round 1.
|
||||
|
||||
So roughly **1.1 GB of a 1.2 GB "photo backup" is cache and duplication**, at the customer's offsite
|
||||
quota and transfer cost.
|
||||
|
||||
### 5. Phase-3 run — the new defect
|
||||
|
||||
`pg_dump` is invoked `--clean --if-exists`, and `psql` with `ON_ERROR_STOP=1` (so an error aborts
|
||||
rather than half-applying — correct). Plain-format pg_dump order is DROP → CREATE TABLE → COPY data
|
||||
→ CREATE INDEX/constraints. The abort landed in the final stage:
|
||||
|
||||
- 10:58:25 replay begins; the DROP + CREATE TABLE + COPY phases succeed (11 assets land)
|
||||
- 10:58:33 **immich-server** logs `Reindexing clip_index` → `Reindexed clip_index`
|
||||
- 10:58:35 the dump's own `CREATE INDEX clip_index` fails: *already exists* → exit 3
|
||||
|
||||
immich-server then logs `Detected schema drift` and lists indexes that are missing and need to be
|
||||
created (`user_updatedAt_id_idx`, `library_ownerId_idx`, `stack_primaryAssetId_idx`,
|
||||
`asset_id_timeline_notDeleted_idx`, …) — the ones the aborted script never reached.
|
||||
|
||||
---
|
||||
|
||||
## Phase 2 — verdict
|
||||
|
||||
| Hypothesis | Verdict | Decisive evidence |
|
||||
|---|---|---|
|
||||
| **H1** — mangled row caused a mis-click; missing-only ran, replay never did | **CONFIRMED** | `placed immich … 34 file(s) merged (missing-only)` at 10:39:55; `reconstituted / safety dump / replaying DB dump` counts all **0**; the reconstitute endpoint appears nowhere in the log |
|
||||
| **H2** — full restore ran but replayed a wrong/stale unit | **REJECTED** | The full path never executed at all. Independently, the staging used `49e7cb46` — the correct pre-delete snapshot, stamped coherent, dump holding 11 assets |
|
||||
| **H3** — replay ran correctly, immich-side hides the assets | **REJECTED** | No replay occurred; the DB was genuinely `asset: 0`. After the Phase-3 replay the assets are visible-by-every-criterion, so nothing immich-side hides them |
|
||||
| **H4 (new)** — the replay races the app's own schema repair | **CONFIRMED** | `clip_index` recreated by immich-server at 10:58:33, dump's CREATE INDEX fails at 10:58:35; resulting schema drift reported by immich itself |
|
||||
|
||||
---
|
||||
|
||||
## Phase 3 — recovery: PARTIAL, stopped as instructed
|
||||
|
||||
One deliberate run, via the exact endpoints the buttons post to (the endpoint route was used rather
|
||||
than a click **because the mangled 4-button row makes the correct target genuinely ambiguous** —
|
||||
finding 1 below):
|
||||
|
||||
1. `POST /backup/offbox/restore` `app=immich mode=full confirm=1` → staged `49e7cb46`, 1.3 G scratch.
|
||||
2. `POST /backup/offbox/reconstitute` `app=immich confirm=1` → safety dump → stop → start → replay →
|
||||
**abort** (H4).
|
||||
|
||||
Result: **photos recovered and visible-by-every-DB-criterion; the operation reported failure; the
|
||||
schema is incomplete.** Per the runbook — state is partially mutated, so **no second attempt was
|
||||
made**. The safety dump from 10:58:11 is intact and untouched.
|
||||
|
||||
> **Screenshot still needed from Viktor** (cannot be captured from SSH): the immich timeline showing
|
||||
> the 11 photos. Requested; not yet held.
|
||||
|
||||
---
|
||||
|
||||
## Phase 4 — findings
|
||||
|
||||
### 1. [HIGH] Restore UX — adjacent buttons whose difference is "data returns vs data cannot return"
|
||||
|
||||
Independent of the H-verdict, and the direct cause of H1:
|
||||
|
||||
- **The second step is hidden.** „Teljes visszaállítás indítása" only appears after
|
||||
„…előkészítése" has been pressed, with zero signposting that a second step exists or that the
|
||||
first one did nothing to the live data.
|
||||
- **The row overflows.** Four buttons plus hint text overlap into an unreadable row, so the honest
|
||||
labels — the ones that distinguish a file-only merge from a real restore — are exactly what gets
|
||||
lost.
|
||||
- **The proven consequence class:** *two adjacent controls whose difference is "your data comes
|
||||
back" versus "your data cannot come back" must not be separable only by layout.* This is now
|
||||
demonstrated, not theorised: a competent operator who had read the code pressed the wrong one.
|
||||
|
||||
Direction (already ruled in principle, spec rides v0.149): a single „Visszaállítás…" guided dialog —
|
||||
one intent, visible phases, the wizard precedent.
|
||||
|
||||
### 2. [HIGH, new] The DB replay races the application's own schema repair
|
||||
|
||||
The reconstitution starts the stack before replaying, because `ImportDump` needs a live container.
|
||||
That hands the application a window in which it recreates schema objects the dump is about to
|
||||
create. Here it cost only the index phase; the data had already landed because pg_dump orders COPY
|
||||
before CREATE INDEX. **That ordering is luck, not design** — a collision earlier in the script
|
||||
aborts before the data and produces a half-restored database reported identically.
|
||||
|
||||
Note the same start-then-replay shape exists on the LOCAL restore path
|
||||
(`RestoreFromRecoveryUnit` → `RecreateStackFromUnit` → `reimportDBDumpsCtx`), so this is a class
|
||||
defect, not an offsite-only one. Direction for v0.149 (not decided here): bring up the DB container
|
||||
alone for the replay and start the app only afterwards, or quiesce the app's schema management for
|
||||
the duration.
|
||||
|
||||
### 3. [MED, new] A partially-successful restore reports as a flat failure
|
||||
|
||||
The customer was told „az adatbázis visszaállítása sikertelen" while their photos were, in fact,
|
||||
restored. This is the mirror image of round 1's defect (success reported over a no-op) and the same
|
||||
class: **the message describes the mechanism's exit status, not the outcome.** Worse here, because
|
||||
the true state — data restored, schema incomplete — is neither "success" nor "failure" and the UI
|
||||
has no way to say it.
|
||||
|
||||
### 4. [MED] Template classification — 1.1 GB of a 1.2 GB backup is cache and duplication
|
||||
|
||||
Candidates to exclude from the offsite capture set, **recorded not changed**:
|
||||
|
||||
- `immich_ml_cache` (786 MiB) — re-downloadable model weights, pure cache. Strong candidate.
|
||||
- `immich_postgres_data` tar (294 MiB) — duplicates the logical `.sql` dump captured beside it.
|
||||
Keeping both doubles the DB's footprint in every snapshot; the dump is already the authoritative
|
||||
copy on the restore path.
|
||||
- `upload/backups/` (18 MiB, immich's own nightly dump) — a backup inside a backup; grows daily.
|
||||
- The stranded pre-v3 `dccc13fe…` tree (~36 MiB) from round 1, still unreferenced by any DB.
|
||||
|
||||
### 5. Standing rulings, carried into the repo
|
||||
|
||||
- **`00-capability-map.md:61`** — ruled: CAMPAIGN-6D's destruction hit the **file tree only**; the
|
||||
database survived in its named volume (`immich_postgres_data` is a named volume in both eras), so
|
||||
"immich end-to-end from offsite alone" **overclaimed scope**. Row → PARTIAL, scope-corrected.
|
||||
- **The 704.6 MiB "discrepancy"** — ruled **resolved, not a defect**: the figure was immich's own
|
||||
Tárhely widget (immich-internal accounting), never a controller page. Closed in the round-1 DIAG.
|
||||
The same explanation covers today's „650 MiB → 1.4 GiB" observation, which likewise does not match
|
||||
the controller's own measurement of the tree (127 MB).
|
||||
|
||||
### 6. Capability map — customer-restore row
|
||||
|
||||
**NOT flipped.** The Phase-3 run recovered the photos but reported failure and left schema drift, so
|
||||
it is not the clean acceptance evidence §9 asks for. Recorded as
|
||||
*"partial evidence captured 2026-07-19 — blocked on H4"* rather than flipped.
|
||||
|
||||
---
|
||||
|
||||
## What was NOT done
|
||||
|
||||
- No code, label or layout fixes — all of the above rides v0.149.
|
||||
- No `restic forget`/`prune`, no snapshot deletion.
|
||||
- The safety dumps were read, never modified or removed.
|
||||
- **No second restore attempt** after the partially-mutating first run.
|
||||
Reference in New Issue
Block a user