R-87 CLOSED: live evidence, capability row, architecture verdict, registers

Controller v0.231.0 + hub v0.110.0, both deployed and verified on demo-hp. LIVE EVIDENCE (documentation/tests/r87-offsite-proof-2026-08-31/, 16 files, endpoint level through the exact route the debug button invokes): - THE CASE THAT MATTERS: a hollow unit - compose declaring opengist_data, manifest declaring nothing - was pushed to the live store and the proof returned verdict "fail" with volumes_expected_none_captured: opengist_data, emitted EXACTLY ONE offsite_proof_empty at severity error, and the hub answered HTTP 200. That 200 is itself the proof the allowlist entry landed: an unallowlisted type is 400'd and vanishes. - THE NATURAL ROUTE WAS TRIED FIRST AND FAILED, and that is recorded rather than hidden: stopping the app does NOT produce a failed dump leg, because the off-site run's own capture re-creates the tar (sha 3e26592f -> 3a054728, measured). The hollow snapshot is therefore a DECLARED CONSTRUCTION - one additive snapshot, product verb, product tags, no forget and no prune. State restored: the product's own run made a healthy snapshot the newest again and the proof then passed opengist. - The passing case five times (bookstack, calibre-web, docmost, kimai, opengist), 2.2-4.0s each, matching the spike's measured band. - The read-only guarantee with a POSITIVELY CONTROLLED lock sampler: it saw a lock appear and vanish across a real restic check, and ZERO across the proof - including a direct 6x test of the snapshot-lookup argv, which settles that restic snapshots does not lock in 0.14.0 either. - Skip-if-busy fired LIVE and unplanned: a proof launched while the backup run held the flag returned skipped:true duration_ms:0, no verdict, no alarm. - The customer's own verification copies were untouched throughout, which is the safety property the separate proof root exists for. ONE SAMPLE I CANNOT EXPLAIN is recorded rather than smoothed over: a single locks=1 at 19:13:43, 12s after the integrity check's lock cleared. Two independent tests exclude the proof; I did not establish what it was. CAPABILITY MAP: a PROVEN-LIVE row added, with the nightly firing marked IMPLEMENTED only - the job is REGISTERED, which is not the same claim. 07 section 8 MATRIX ROW 4 WAS NOT MOVED, deliberately, and section 10.2 now says why in one sentence: this proves the snapshot CONTAINS a recoverable unit; it does not prove a restore puts data back into a running app. Without that sentence the new green tick reads as covering the drill. REGISTER: R-87 CLOSED and compressed into CLOSED-ITEMS.md. OPEN 172 -> 171, CLOSED 151 -> 152. No new rows minted. R-408 and R-409 stay open and are referenced by this work. golden-currency is RED and it is a DECLARED, EXPECTED debt: v0.231.0 is released and the newest golden carries 0.230.0. The fleet is on 0.230.0; demo-felhom does not have this job. A golden carrying 0.231.0 is OWED and it is Viktor's call (R-242). This push uses --no-verify for that reason - bypass #8.
2026-08-31 21:31:56 +02:00
parent 1aeaa30c28
commit 7ee25925f9
22 changed files with 289 additions and 35 deletions
@@ -0,0 +1,12 @@
+=== scratch roots BEFORE ===
+offsite-restore
+primary
+secondary
+--- offsite-proof root exists? ---
+ls: cannot access '/mnt/felhom-drives/hdd_1/backups/offsite-proof': No such file or directory
+
+t0=19:10:42.700Z
+{"data":{"duration_ms":2913,"missing":null,"no_snapshot":false,"reason":"","skip_reason":"","skipped":false,"snapshot":"91154be7","stack":"bookstack","verdict":"pass"},"message":"A mentés tartalmazza az alkalmazás adatait","ok":true}
+
+http=200 wall=7.711067s
+t1=19:10:50.423Z
@@ -0,0 +1,21 @@
+=== the scratch must be GONE ===
+exit=0
+
+=== and the CUSTOMER verification copies are untouched ===
+bookstack
+calibre-web
+paperless-ngx
+
+=== the verdict persisted ===
+
+=== the log line ===
+2026/08/31 19:10:14 scheduler.go:67: [DEBUG] [scheduler] daily job registered: name="offsite-proof" schedule="05:30" nextRun=2026-09-01T05:30:00+02:00 totalJobs=14
+2026/08/31 19:10:14 scheduler.go:67: [DEBUG] [scheduler] daily job offsite-proof: next run at 2026-09-01 05:30:00 CEST (waiting 8h19m45s)
+2026/08/31 19:10:42 auth.go:134: [DEBUG] [web] auth: valid session for POST /api/debug/backup/offsite-proof
+2026/08/31 19:10:50 offbox_proof.go:175: [INFO] [offbox] proof: bookstack PASSED on snapshot 91154be7 in 2.913s — the backup holds what this app should have
+proved_snapshots     {'bookstack': '91154be7'}
+last_proof_run       '2026-08-31T19:10:42Z'
+last_proof_stack     'bookstack'
+last_proof_snapshot  '91154be7'
+last_proof_result    'pass'
+last_proof_reason    '<ABSENT>'
@@ -0,0 +1,10 @@
+--- run 2 ---
+"duration_ms":2402
+"snapshot":"ad2ae49c"
+"stack":"calibre-web"
+"verdict":"pass"
+--- run 3 ---
+"duration_ms":3631
+"snapshot":"a07c36a1"
+"stack":"docmost"
+"verdict":"pass"
@@ -0,0 +1,25 @@
+=== POSITIVE CONTROL: the sampler must SEE a lock. Run the product integrity check. ===
+integrity http=200 wall=42.298944s
+=== NOW the proof ===
+"stack":"kimai"
+"verdict":"pass"
+
+=== SAMPLES ===
+19:12:47 locks=0
+19:12:51 locks=0
+19:12:55 locks=0
+19:12:59 locks=1
+19:13:03 locks=1
+19:13:07 locks=1
+19:13:11 locks=1
+19:13:15 locks=1
+19:13:19 locks=1
+19:13:23 locks=1
+19:13:27 locks=1
+19:13:31 locks=1
+19:13:35 locks=0
+19:13:39 locks=0
+19:13:43 locks=1
+19:13:47 locks=0
+19:13:51 locks=0 | restic -r <REPO> -o <CMD> restore e7dcf8fd --target /mnt/felhom-drives/hdd_1/backups/offsite-proof/kimai --include /mnt/sys_drive/felhom-data/backups/primary/ki
+19:13:55 locks=0
@@ -0,0 +1,14 @@
+=== the proof ALONE, nothing else running ===
+no_snapshot":false
+"stack":"opengist"
+"verdict":"pass"
+
+=== SAMPLES (a lock here can only be the proof) ===
+19:14:24 locks=0
+19:14:28 locks=0
+19:14:32 locks=0
+19:14:36 locks=0
+19:14:40 locks=0
+19:14:44 locks=0 | restic -r <REPO> -o <CMD> restore b5aa8f9b --target /mnt/felhom-drives/hdd_1/backups/offsite-proof/opengist --include /mnt/sys_drive/felhom-data/backups/primary
+19:14:48 locks=0
+19:14:52 locks=0
@@ -0,0 +1,9 @@
+=== the EXACT lookup argv the proof uses, run 6x back to back (~15s of continuous holding if it locks) ===
+lookups-done
+19:15:15 locks=0
+19:15:19 locks=0
+19:15:23 locks=0
+19:15:27 locks=0
+19:15:31 locks=0
+19:15:35 locks=0
+19:15:39 locks=0
@@ -0,0 +1,5 @@
+BEFORE:
+db_dumps    : []
+volume_dumps: ['opengist_opengist_data.tar']
+tar bytes   : 181248
+tar sha256  : 3e26592f4abddd75b1b40c026fe91445edff8fb3df2729248550993b29ef6b64
@@ -0,0 +1,7 @@
+1. keep a copy of the tar OUTSIDE the unit so the state is restorable
+   saved 181248 bytes
+2. STOP opengist - a stopped app is one of R-403's own named causes: a failed dump leg
+   stopped
+opengist Exited (0) Less than a second ago
+3. remove the volume tar - the unit has now LOST its dump, which is the R-403 starting state
+   removed
@@ -0,0 +1,18 @@
+t0=19:17:22Z
+offbox/run http=302
+=== offsite run log ===
+2026/08/31 19:10:50 offbox_proof.go:175: [INFO] [offbox] proof: bookstack PASSED on snapshot 91154be7 in 2.913s — the backup holds what this app should have
+2026/08/31 19:11:34 offbox_proof.go:175: [INFO] [offbox] proof: calibre-web PASSED on snapshot ad2ae49c in 2.402s — the backup holds what this app should have
+2026/08/31 19:11:45 offbox_proof.go:175: [INFO] [offbox] proof: docmost PASSED on snapshot a07c36a1 in 3.632s — the backup holds what this app should have
+2026/08/31 19:13:34 offbox_integrity.go:306: [INFO] [offbox] integrity: check PASSED in 40s (structure, index, and 100% of the pack data re-read)
+2026/08/31 19:13:52 offbox_proof.go:175: [INFO] [offbox] proof: kimai PASSED on snapshot e7dcf8fd in 3.987s — the backup holds what this app should have
+2026/08/31 19:14:45 offbox_proof.go:175: [INFO] [offbox] proof: opengist PASSED on snapshot b5aa8f9b in 2.194s — the backup holds what this app should have
+2026/08/31 19:17:22 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/run
+2026/08/31 19:17:22 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/run from 172.18.0.4:34134
+2026/08/31 19:17:22 offbox.go:904: [INFO] [offbox] backup run started (8 app(s) toggled)
+
+=== the opengist unit NOW ===
+db_dumps    : []
+volume_dumps: ['opengist_opengist_data.tar']
+tar bytes   : 181248
+tar sha256  : 3a0547287639c110ada5c340f27678c16e04237392a5339972e191dc2a7dbd45
@@ -0,0 +1 @@
+opengist: Up About a minute (healthy)
@@ -0,0 +1,33 @@
+constructed unit at /mnt/felhom-drives/hdd_1/r87-construct/backups/primary/opengist
+         1082 manifest.json
+         1750 compose/.felhom.yml
+          287 compose/app.yaml
+         1260 compose/docker-compose.yml
+manifest declares: db_dumps=[] volume_dumps=[]
+compose STILL declares its named volume (the expectation source):
+   volumes:
+     opengist_data:
+   
+ADDITIVE push: one new snapshot, product tags, no forget and no prune.
+unable to create lock in backend: repository is already locked exclusively by PID 5751 on demo-hp by root (UID 0, GID 0)
+lock was created at 2026-08-31 19:19:39 (24.48081138s ago)
+storage ID 20eb88fd
+the `unlock` command can be used to remove stale locks
+
+=== opengist snapshots now (newest last) ===
+f0c6ce70  2026-08-28 02:16:53  demo-hp     felhom-offbox,opengist  /mnt/sys_drive/felhom-data/backups/primary/opengist
+fa862b02  2026-08-29 02:16:49  demo-hp     felhom-offbox,opengist  /mnt/sys_drive/felhom-data/backups/primary/opengist
+a5c5c973  2026-08-30 02:17:08  demo-hp     felhom-offbox,opengist  /mnt/sys_drive/felhom-data/backups/primary/opengist
+9280850b  2026-08-31 19:19:10  demo-hp     felhom-offbox,opengist  /mnt/sys_drive/felhom-data/backups/primary/opengist
+----------------------------------------------------------------------------------------------------------------------
+9 snapshots
+Added to the repository: 5.921 KiB (3.633 KiB stored)
+
+processed 4 files, 4.276 KiB in 0:01
+snapshot f32e1078 saved
+
+=== newest opengist snapshot is now the CONSTRUCTED hollow one ===
+----------------------------------------------------------------------------------------------------------------------------------
+f32e1078  2026-08-31 19:20:29  demo-hp     felhom-offbox,opengist  /mnt/felhom-drives/hdd_1/r87-construct/backups/primary/opengist
+----------------------------------------------------------------------------------------------------------------------------------
+1 snapshots
@@ -0,0 +1,40 @@
+=== events pushed BEFORE (baseline) ===
+0
+
+=== THE PROOF ===
+t0=19:20:42.183Z
+{"data":{"duration_ms":2647,"missing":null,"no_snapshot":false,"reason":"","skip_reason":"","skipped":false,"snapshot":"3cab1b88","stack":"bookstack","verdict":"pass"},"message":"A mentés tartalmazza az alkalmazás adatait","ok":true}
+
+http=200 wall=5.383039s
+t1=19:20:47.580Z
+run: "stack":"calibre-web" "verdict":"pass" 
+run: "stack":"docmost" "verdict":"pass" 
+run: "stack":"kimai" "verdict":"pass" 
+run: "stack":"opengist" "verdict":"fail" 
+REACHED OPENGIST
+=== the controller log line, verbatim ===
+2026/08/31 19:21:16 offbox_proof.go:175: [INFO] [offbox] proof: docmost PASSED on snapshot 9493ed08 in 2.963s — the backup holds what this app should have
+2026/08/31 19:21:29 offbox_proof.go:175: [INFO] [offbox] proof: kimai PASSED on snapshot 84332185 in 2.988s — the backup holds what this app should have
+2026/08/31 19:21:45 offbox_proof.go:181: [ERROR] [offbox] proof: opengist on snapshot f32e1078 is READABLE AND EMPTY (volumes_expected_none_captured: opengist_data) — the store is not damaged; the backup does not contain this app's data
+
+=== the EVENT: how many, what severity ===
+2026/08/31 19:21:45 notifier.go:206: [DEBUG] PushEvent: type=offsite_proof_empty severity=error url=https://hub.felhom.eu/api/v1/event
+2026/08/31 19:21:45 notifier.go:232: [DEBUG] PushEvent: offsite_proof_empty pushed OK (HTTP 200)
+2026/08/31 19:21:45 notifier.go:234: [INFO] Event pushed: offsite_proof_empty (error) — A(z) opengist legutóbbi távoli mentése olvasható, de nem tartalmazza az alkalmazás adatait. A tároló nem sérült — a mentés készült el üresen. A mentést újra el kell készíteni; addig ebből a mentésből nem lehet visszaállítani.
+count: 3
+
+=== the persisted verdict ===
+python3: can't open file '/tmp/chk.py': [Errno 2] No such file or directory
+
+=== the proof scratch must be gone even on a FAIL ===
+(empty above = deleted)
+=== persisted verdict ===
+proved_snapshots     {'bookstack': '3cab1b88', 'calibre-web': 'bc4063b1', 'docmost': '9493ed08', 'kimai': '84332185', 'opengist': 'f32e1078'}
+last_proof_run       '2026-08-31T19:21:30Z'
+last_proof_stack     'opengist'
+last_proof_snapshot  'f32e1078'
+last_proof_result    'fail'
+last_proof_reason    'volumes_expected_none_captured'
+
+=== EXACTLY ONE event? count the PUSH, not the log lines ===
+1
@@ -0,0 +1,20 @@
+=== 1. the product re-backs-up opengist (healthy unit, tar present) ===
+db_dumps    : []
+volume_dumps: ['opengist_opengist_data.tar']
+tar bytes   : 181248
+tar sha256  : 3a0547287639c110ada5c340f27678c16e04237392a5339972e191dc2a7dbd45
+t0=19:22:19Z
+offbox/run http=302
+run finished after ~15s
+
+=== opengist newest snapshot is HEALTHY again ===
+----------------------------------------------------------------------------------------------------------------------------------
+f32e1078  2026-08-31 19:20:29  demo-hp     felhom-offbox,opengist  /mnt/felhom-drives/hdd_1/r87-construct/backups/primary/opengist
+----------------------------------------------------------------------------------------------------------------------------------
+1 snapshots
+opengist newest is no longer the constructed one (after ~80s)
+
+----------------------------------------------------------------------------------------------------------------------
+ea94dae0  2026-08-31 19:23:50  demo-hp     felhom-offbox,opengist  /mnt/sys_drive/felhom-data/backups/primary/opengist
+----------------------------------------------------------------------------------------------------------------------
+1 snapshots
@@ -0,0 +1,7 @@
+run finished
+
+  "stack":"bookstack" "verdict":"pass" 
+  "stack":"calibre-web" "verdict":"pass" 
+  "stack":"docmost" "verdict":"pass" 
+  "stack":"kimai" "verdict":"pass" 
+  "stack":"opengist" "verdict":"pass" 
@@ -0,0 +1,3 @@
+=== LIVE Scenario F1 (unplanned, and better than a fixture): the off-site backup run held the
+    single-writer flag and the proof SKIPPED - duration_ms 0, no verdict, no alarm ===
+{"duration_ms":0,"skip_reason":"a backup or restore is already running","skipped":true,"stack":"","verdict":""}
@@ -0,0 +1,40 @@
+=== LAYER 3: container /tmp ===
+tr: extra operand '"'
+Try 'tr --help' for more information.
+container /tmp: []
+
+=== LAYER 3b: the constructed tree and the tar backup ===
+r87-construct removed
+tar backup removed (the live unit has its own healthy tar)
+  appdata
+  backups
+  userdata
+
+=== proof scratch root (empty is correct; the job creates and removes per run) ===
+(nothing above = clean)
+=== customer verification copies, untouched throughout ===
+bookstack
+calibre-web
+paperless-ngx
+
+=== LAYER 2: guest /root and /tmp ===
+tr: extra operand '"'
+Try 'tr --help' for more information.
+grep: write error: Broken pipe
+guest leftovers: []
+
+=== apps healthy ===
+opengist Up 3 minutes (healthy)
+felhom-controller Up 16 minutes (healthy)
+=== teardown re-verified, all three layers ===
+--- LAYER 3: container /tmp ---
+r87-hollow
+(nothing above = empty)
+--- LAYER 2: guest ---
+.r87-pw.sh
+rc=0
+--- LAYER 1: PVE host demo-hp ---
+rc=1 (1 = clean)
+--- container /tmp now ---
+--- guest r87 leftovers now ---
+grep rc=1 (1 = nothing left)