R-87 SPIKE: measured, do not build it as written (R-407..R-409 filed)
gates / gates (push) Failing after 17s
gates / gates (push) Failing after 17s
Spike. NO production code. No version bump, no build, no deploy, no golden.
felhom-controller and felhom-agent were READ ONLY. The fleet stays on v0.230.0.
Q1 restic is 0.14.0 (go1.19.8, bookworm 12.15) - the four source comments asserting
it are CONFIRMED, not corrected.
Q2 --verify DOES exist and is NOT a content check. Red-proof: one byte changed in a
restored 160 MB tar with size and mtime preserved passed clean, rc=0. Verify took
131 ms on a 213 MB / 7-file tree, which cannot be hashing. A size or mtime mismatch
causes a silent re-download, not a failure. Controls: --target 1 hit, four post-0.14
flags and a nonsense string 0 hits each. Neither --verify nor --no-lock appears
anywhere in the controller source.
Q3 no reference for "correct" exists. restic ls --json carries no content hash in
0.14.0, and the unit manifest hashes 4918 B of a 213231242 B unit - 0.0023 percent,
the config files and not the dumps or the tars. R-409.
Q4 it is CHEAP. All 8 apps / 774378123 B logical restored back to back in 25 s, against
40257 ms for the weekly 100 percent check beside it. Individual restores 2253-3978 ms
regardless of size: cost is per-snapshot round-trip plus ~1 s per 200 MB. Peak scratch
is the app's full logical size. The 1.1 MB restic cache is index only and hides nothing
(--no-cache 5423 ms vs cached 3198 ms, trees byte-identical).
Q5 skip-if-busy stays right at 25 s against a 2m52s nightly backup. But
RestoreOffboxScratch takes NO acquireRunning, while offbox_integrity.go:28 asserts
every off-site operation does. R-408.
Q6 observed with a positively-controlled lock sampler: restic restore takes NO lock;
restic check DOES (locks 0 -> 1 for nine samples -> 0 across the check, zero across two
restores). The product writes anyway - unlockStale runs `restic unlock`, a delete verb,
before every restore (offbox_restore.go:289). The task's lead was right in direction and
wrong in mechanism. R-95's constraint IS satisfiable: --no-lock plus skipping unlockStale
writes nothing, and both mechanisms exist unused. Neither was fixed - the task forbids it.
offbox_integrity.go:255's "It NEVER writes to the repository" is R-407.
Q7 THE DECIDING ONE: of R-353/354/356/358/403 an unattended scratch-restore would have
caught ONE (R-356). The value is elsewhere, and the weekly check structurally cannot
reach it: `check` proves the stored bytes are the stored bytes, never that we stored the
RIGHT thing. A hollow unit backs up, checks at 100 percent and restores cleanly and
recovers nothing - R-403, measured in bytes on 31 August.
RECOMMENDATION: option C, the NARROW test - one app a night, restored to scratch, checked
against its own manifest.json through the existing unitCarriesData, scratch deleted, the
SNAPSHOT recorded as the proof. Options A (do not build) and B (scheduled attended drill)
considered explicitly; B is weakest because it is what already happens. R-87 should be
RE-SCOPED, not built as written, and that is Viktor's call - the row stays open carrying
the verdict and STATUS.md item 4 asks it in plain words.
Also corrected in 07-backup-architecture.md: matrix rows 4 and 10 both said "the depth
that ships ON does not re-read pack contents (R-399)". R-399 CLOSED in v0.228.0 and the
depth is 100 percent. Two stale cells, fixed, and the spike verdict added beside them.
Row 4's verdict is UNCHANGED by the spike and now says so.
Teardown: all three layers, none of them "nothing was created" - 6 files on the PVE host,
9 in the guest, 5 plus 2 run-flags in the container, all removed and verified empty. The
four scratch directories this session's restores created were removed; three that
pre-date the session were left alone. Two state changes recorded rather than hidden: the
control integrity run recorded its verdict (depth structure -> 100%, due-ness +7 days),
and four restores appear in the controller log. Nothing was written to the off-site
repository by hand.
Evidence: documentation/audits/evidence-spike-restic-restore-2026-08-31/ - 31 files,
every one pulled off the box BEFORE teardown (R-320).
golden-currency is RED at this commit and was already red at dddcc80. Pre-existing, not
this session's debt. Second --no-verify push of the day for that reason; R-404's count
goes six -> seven and its row says so.
Ceiling R-406 -> R-409.
This commit is contained in:
@@ -0,0 +1,176 @@
|
||||
# REPORT — R-87 spike: can the off-site copy be restore-tested without a person? (2026-08-31)
|
||||
|
||||
Written as `REPORT-r87-spike.md`, not `REPORT.md`: this repo's `CLAUDE.md` says the shared report is
|
||||
overwritten and two sessions clobber each other.
|
||||
|
||||
**Findings document (the deliverable):** `documentation/audits/SPIKE-restic-restore-test-2026-08-31.md`
|
||||
**Evidence:** `documentation/audits/evidence-spike-restic-restore-2026-08-31/` — 31 files.
|
||||
|
||||
---
|
||||
|
||||
## 1. Baselines, re-checked at the start
|
||||
|
||||
| repo | `main` @ | version | matched the task's stated baseline? |
|
||||
|---|---|---|---|
|
||||
| `felhom-controller` | `2d802d75e88616d86cbade8a0e16965c2b85771c` | v0.230.0 | yes |
|
||||
| `felhom.eu` | `dddcc808be95d1c89b276b4d791491bad3c96bba` | — | yes; clean tree, `HEAD == origin/main` |
|
||||
| `felhom-agent` | `058b945` | v0.130.0 | yes |
|
||||
|
||||
## 2. Part 1 — the register correction
|
||||
|
||||
- **The mis-filing commit:** `ef6ac6f`, 2026-08-22, *"One register, enforced by a gate; closed work
|
||||
compressed into siblings (R-376..R-378)"*. Established by `git log -S '**R-87**'` on both register
|
||||
files — it is the only commit that added the row to `CLOSED-ITEMS.md` and the only one that removed
|
||||
it from `OPEN-ITEMS.md`. **The history settled it; no guess was needed.**
|
||||
- **It is a survivor of R-378, not a separate incident.** R-378 records six rows moved wrongly by that
|
||||
same sweep and restored in the same session. R-87 is a **seventh it missed**, and it escaped because
|
||||
its state cell led with `READY` and carried the word `closed` later, describing a different row.
|
||||
- **My own count, reproduced:** **1** mis-filed row under the leading-verdict predicate. The same scan
|
||||
convicts **3** if it reads the whole state cell (R-224 and R-260 are false positives — long prose
|
||||
verdicts containing "open"/"OPEN") and **144** if it reads the whole row. The task author's count of
|
||||
one is confirmed, and only under the predicate R-378 argues for.
|
||||
- **The gate:** `scripts/closed_register_gate.py`. Two rules. **Red-proof rule 1:** a planted `READY`
|
||||
row convicts by name, rc=1; removing it leaves the file byte-identical. **Red-proof rule 2:** a
|
||||
planted duplicate id convicts, rc=1. **Negative control:** run against the files *as pushed*
|
||||
(`HEAD:`), it convicts R-87 at L72 and R-398 at L139, rc=1. **Registered LAST**, as the 12th gate in
|
||||
`repo_gates.py`, after it was green.
|
||||
- **Also corrected:** `R-398` had a row in both registers (a deliberate cross-reference stub). Now
|
||||
prose beneath the table.
|
||||
|
||||
## 3. Q1–Q7, one paragraph each
|
||||
|
||||
**Q1 — restic 0.14.0**, `go1.19.8`, Debian bookworm 12.15, from the running container. The four source
|
||||
comments asserting 0.14.0 are **confirmed**. Method: `docker exec felhom-controller restic version`.
|
||||
|
||||
**Q2 — `--verify` exists and is NOT a content check.** `restic restore --help` lists
|
||||
`--verify verify restored files content`; positive control `--target` = 1 hit, negative controls
|
||||
`--delete/--dry-run/--overwrite/--sparse` and a nonsense string = 0 hits each. Neither `--verify` nor
|
||||
`--no-lock` appears anywhere in the controller source (`grep -rn` rc=1, with `--json`/`--target` as
|
||||
the positive control). **Red-proof:** one byte changed in a restored 160 MB tar with size and mtime
|
||||
preserved — `restore --verify` **passed clean, rc=0**. Verify took **131 ms** on a 213 MB / 7-file
|
||||
tree, which cannot be hashing. A size or mtime mismatch causes a silent **re-download**, not a
|
||||
failure. **So restic cannot tell us a restore produced correct files.**
|
||||
|
||||
**Q3 — no reference for "correct" exists today.** `restic ls --json` file nodes in 0.14.0 carry no
|
||||
content hash. The recovery unit's `manifest.json` hashes three config files — **4 918 B of a
|
||||
213 231 242 B unit, 0.0023 %** — and not the DB dump or the volume tars. A planted sentinel is a drill
|
||||
technique and does not transfer; the live data drifts. **What the manifest CAN answer is
|
||||
completeness**, through the existing `unitCarriesData` (`r403_hollow.go:40`), with no new metadata.
|
||||
Filed as R-409.
|
||||
|
||||
**Q4 — ~4 s per app, 25 s for all eight, cheaper than the weekly check.** Through the product's own
|
||||
path: docmost unit 9 s, kimai full 11 s. Raw restic, all 8 snapshots / **774 378 123 B logical** back
|
||||
to back: **25 s**, individual times 2 253–3 978 ms *regardless of size* (185 KB → 2.25 s, 213 MB →
|
||||
3.20 s). The cost is per-snapshot round-trip plus ≈ 1 s per 200 MB. Peak scratch = the app's full
|
||||
logical size, 213 272 202 B for the largest. The restic cache is **1.1 MB** (index only) and does not
|
||||
hide the cost: `--no-cache` 5 423 ms vs cached 3 198 ms, trees byte-identical. **Against R-359's
|
||||
35.0 s / 39.2 s: the same 100 % check re-measured today is 40 257 ms — so restore-testing the whole
|
||||
box costs LESS than one weekly check.** Extrapolation to 10×/100× is in the findings doc, **labelled
|
||||
as extrapolation**, with scratch space named as the constraint that binds before time does; the
|
||||
single-store hole is R-401's.
|
||||
|
||||
**Q5 — skip-if-busy stays right, and a bigger thing is wrong.** Scheduler registrations read off the
|
||||
box (CEST): db-dump 02:30, tier2 03:30, **offbox-backup 04:15 (2m52s measured)**, abandon-sweep 05:10,
|
||||
**offsite-integrity 06:00 (40.3 s)**. A 25 s hold is seconds, not minutes, and there is an empty gap
|
||||
04:18–06:00. **But `RestoreOffboxScratch` takes no `acquireRunning` at all** — nine non-test callers,
|
||||
it is not one — while `offbox_integrity.go:28` asserts *"Every off-site operation takes
|
||||
`acquireRunning`"*. `restore_wizard.go:174` records the same fact independently. Filed as **R-408**.
|
||||
|
||||
**Q6 — the restore itself writes nothing; the product writes anyway; and `check` writes a lock.**
|
||||
Observed with a lock sampler and an argv sampler, both inside the container, the repo URL redacted at
|
||||
source. **Positive control:** across the product's integrity run the repo went `locks=0` →
|
||||
`locks=1 id=81fd4d42…` for nine consecutive samples → `locks=0`. **The same instrument saw zero locks
|
||||
across two restores**, so `restic restore` in 0.14.0 does not lock. Observed argv for one restore:
|
||||
`snapshots latest --tag <app> --json`, then **`unlock`**, then `restore <id> --target …`. The middle
|
||||
one is `unlockStale` (`offbox_restore.go:289`), unconditional, a **delete verb**. **§5's lead was
|
||||
right in direction and wrong in mechanism** — the write is `unlockStale`, not `resticStep`'s
|
||||
escalation. **The constraint IS satisfiable:** `--no-lock` + skipping `unlockStale` writes nothing,
|
||||
and both mechanisms exist in 0.14.0 unused. `offbox_integrity.go:255`'s *"It NEVER writes to the
|
||||
repository"* is filed as **R-407**. **Neither was fixed** — §7 forbids it.
|
||||
|
||||
**Q7 — one of five.** R-353 (a *local* restore path) **no**; R-354 (no volume-replay leg, after the
|
||||
scratch) **no**; **R-356 (refused every driveless app) YES — five of eight apps on this box would
|
||||
have fired it on the first night**; R-358 (needs a part-way failure) **no**; R-403 (destroyed a
|
||||
*local* copy) **no as filed, yes for the shape**. **The honest verdict is "few", and it points
|
||||
elsewhere:** `check` proves the stored bytes are the stored bytes, never that we stored the *right*
|
||||
thing. A hollow unit backs up, checks at 100 % and restores cleanly, and recovers nothing — R-403,
|
||||
measured in bytes nine days ago. Nothing asks that question on any tier.
|
||||
|
||||
## 4. Recommendation
|
||||
|
||||
Three options with costs and a do-nothing outcome are in the findings document. **I would pick option
|
||||
C — the narrow test:** one app a night, restored to scratch, checked against its own `manifest.json`,
|
||||
scratch deleted, the snapshot recorded as the proof. ~4 s and ≤ 213 MB per night; catches R-356 and
|
||||
the R-403 class; needs no new metadata. **It must use `--no-lock`, skip `unlockStale`, and take
|
||||
`acquireRunning`** — all three established by this spike. **Options A (do not build) and B (scheduled
|
||||
attended drill) were considered explicitly and are argued in the document; B is the weakest, because
|
||||
it is what already happens.** **R-87 should be RE-SCOPED, not built as written — and that is Viktor's
|
||||
call**, so the row stays open carrying the verdict, and `STATUS.md` item 4 asks it in plain words.
|
||||
|
||||
## 5. Evidence
|
||||
|
||||
`documentation/audits/evidence-spike-restic-restore-2026-08-31/`, 31 files, numbered by question.
|
||||
**Every file was pulled off the box before any teardown** (R-320) — including the two in-container
|
||||
sampler logs, which were `cat`ed to DooPlex before the container `/tmp` was cleared.
|
||||
|
||||
## 6. Probes removed — all three layers, and none of them is "nothing was created"
|
||||
|
||||
| layer | created | after teardown |
|
||||
|---|---|---|
|
||||
| PVE host `/root` | 6 scripts + one 0600 password file | `ls \| grep` → nothing |
|
||||
| guest 9201 `/root`, `/tmp` | 9 files | grep → nothing |
|
||||
| container `/tmp` | 5 files + 2 run-flags | `/tmp` lists empty; no restic process left |
|
||||
|
||||
**Scratch directories:** the four created by this session's restores (`docmost`, `kimai`,
|
||||
`privatebin`, `opengist`) were removed. Three (`bookstack`, `calibre-web`, `paperless-ngx`) pre-date
|
||||
this session and were **left alone**. The local password copy was `shred -u`'d.
|
||||
|
||||
**Two state changes recorded rather than hidden:** the integrity check run as the lock positive
|
||||
control **recorded its verdict** (`last_integrity_check` → `2026-08-31T13:41:28Z`, depth `structure` →
|
||||
**`100%`**, due-ness advanced 7 days), and four restores plus two logins appear in the controller log.
|
||||
**Nothing was written to the off-site repository by hand.**
|
||||
|
||||
## 7. Register
|
||||
|
||||
| id | action |
|
||||
|---|---|
|
||||
| **R-87** | **moved back to `OPEN-ITEMS.md`** (verbatim from `ef6ac6f^`, beside R-95), then updated with the spike verdict and a re-scope proposal |
|
||||
| **R-398** | de-tabled in `CLOSED-ITEMS.md`; the open row is the record |
|
||||
| **R-404** | bypass count corrected six → **seven** (this session's Part 1 push) |
|
||||
| **R-405** | filed + **CLOSED** — the mis-file, the reproduced count, the gate |
|
||||
| **R-406** | filed — two findings share the id R-133 |
|
||||
| **R-407** | filed — `restic check` takes a lock; the comment says it never writes |
|
||||
| **R-408** | filed — `RestoreOffboxScratch` takes no `acquireRunning` |
|
||||
| **R-409** | filed — the unit manifest hashes 0.002 % of the unit |
|
||||
|
||||
**Register size:** `OPEN-ITEMS.md` **165 → 171** rows (+R-87 restored, +R-405..R-409); `CLOSED-ITEMS.md` **153 → 151** (−R-87, −R-398).
|
||||
Ceiling **R-404 → R-409**.
|
||||
|
||||
`python3 scripts/unproven.py --summary`: 55 claims, walked 20 / partial 17 / built 14 / missing 4,
|
||||
**NOT WALKED 35 of 55 — unchanged by this session**, which shipped no product claim.
|
||||
|
||||
## 8. No controller code changed and no golden is owed
|
||||
|
||||
`felhom-controller` and `felhom-agent` were **read only**. No version bump, no build, no deploy, no
|
||||
golden. The fleet stays on v0.230.0. **The one golden debt that exists — v0.230.0 released with the
|
||||
newest bake at 0.229.0 — was already red at `dddcc80` before this session started** and belongs to
|
||||
that release, not to this task; `golden_currency_gate.py` was the only failing gate at every point in
|
||||
this session, before and after.
|
||||
|
||||
**`git push --no-verify` was used, twice, for exactly that reason** — records-only pushes meeting the
|
||||
golden gate. That is R-404's subject and the count is updated in its row.
|
||||
|
||||
## 9. Observations — noticed, not acted on
|
||||
|
||||
- `paperless-ngx` has an off-site snapshot under that tag and none under `paperless`; `filebrowser`
|
||||
has none at all (it is infrastructure, so that may be correct). Not chased.
|
||||
- `CLOSED-ITEMS.md` rows **R-399** and **R-400** supply two columns where the table declares four —
|
||||
they render with no `Shipped` and no `Evidence`. The new gate warns rather than convicts, because an
|
||||
empty state cell is not an open state word.
|
||||
- Two rows (**R-309**, **R-351**) carry a `|` inside their body, shifting their own cells. Named as
|
||||
the gate's first residual hole.
|
||||
- The controller image has **no `ps` and no `python3`**. `/proc/*/cmdline` is the substitute that
|
||||
works, and it is worth knowing before writing any probe that runs in there.
|
||||
- The guest scheduler logs in **CEST**, not UTC — `offbox-backup scheduled for 2026-09-01 04:15 CEST`
|
||||
against a `last_run` of `02:17:57Z`. Consistent, and the opposite of what the project memory says
|
||||
about guest time.
|
||||
Reference in New Issue
Block a user