soak drill phases 0-4: R-408's hazard is REAL and reachable; R-357 finally live (R-411..R-413)
gates / gates (push) Failing after 17s
gates / gates (push) Failing after 17s
Overnight soak on demo-hp, phases 0-4 of 7. Evidence documentation/audits/DRILL-soak-2026-08-31/. No production code written, no golden, no version bump - findings only. PHASE 1 FAIL - R-411. The R-408 hazard was only ever reasoned about; tonight it was measured through the product's own endpoints. restic stats TAKES A LOCK (clean-room: nothing else running, 4x stats, sampler reads locks=1). A customer full-restore runs stats in its preparation while holding NO acquireRunning, so the integrity check is not blocked, runs, meets that lock, and resticStep escalates to unlock --remove-all - the sampler caught "restore ..." and "unlock --remove-all" in the SAME sample at 20:50:51. The log calls it "a stale exclusive lock left by a previous crash"; there was no crash. THE CUSTOMER-FACING CONSEQUENCE IS CONTAINED and that is R-359 working: the check was classified Unreachable, NOT damage, so no alarm and due-ness held. The opposite direction is FENCED - five restores fired into a running check at 5/15/25/35/40s were all refused by restoreOpBlocked with zero restic invoked. PHASE 2 FAIL - R-412, and it is the natural instance of R-403's shape that yesterday's session had to hand-build. A lost primary unit is rebuilt by the capture WITHOUT its volume dumps (185664 B -> 4382 B, volume_dumps: None), and the off-site backup then ships it and logs "backed up opengist ... 0 mandatory path(s)" - a success line over a backup holding none of the app's data. PHASE 2 also R-413: the R-87 proof CAUGHT that hollow snapshot unattended - verdict "fail", volumes_expected_none_captured: opengist_data, one offsite_proof_empty at severity error, while the four apps ahead of it in the rotation passed. 2.3 stale marker PASS, 2.4 two restores PASS, 2.5 corrected the runbook's premise (RunTier2 has zero acquireRunning and zero restic references - a local mirror cannot collide with the repo, so the proof correctly does not skip for it). PHASE 3 PASS - R-357 live-validated at last, six days owed. A real full filesystem (1900544 B free vs 5878421 B needed) on a separate 1 TB device that does not back Docker. Refused BEFORE StopStack: app "Up 6 minutes (healthy)" unchanged, 0 safety dumps, live userdata tree fingerprint 5a9b2db75dfd4ba4131adb3255670472 unchanged, message names both numbers in Hungarian. Ballast removed, the SAME restore then worked and the fingerprint is still identical. On the same full disk the Tier-2 run, the proof and the integrity check all behaved: the proof refused before any download through the shared unitOnlyHeadroom gate extracted today, reached no verdict and did not alarm. PHASE 4 PASS - the false-alarm control the whole R-87 design rests on now EXISTS. Found by reading all 53 catalogue composes: bentopdf is the only template with neither a database service nor a named volume. Deployed, backed up, proved: PASSED in 2.224s with zero alarms. Four of my own instrument errors were caught by their own controls before any result was believed: a hub log line used as a controller positive control, a grep pattern that missed a registered job, a heredoc that mangled a planted marker, and a catalogue scan that read 0 of 0 apps from the wrong path. Phases 5-7 to follow: the real nightly cycle with injected faults, the untouched observer, and teardown.
This commit is contained in:
@@ -0,0 +1,4 @@
|
||||
=== demo-hp ===
|
||||
gitea.dooplex.hu/admin/felhom-controller:0.231.0 Up About an hour (healthy)
|
||||
=== demo-felhom ===
|
||||
gitea.dooplex.hu/admin/felhom-controller:0.230.0 Up 6 hours (healthy)
|
||||
@@ -0,0 +1,6 @@
|
||||
=== hub version (live image) ===
|
||||
gitea.dooplex.hu/admin/felhom-hub:0.110.0
|
||||
=== golden / floor ===
|
||||
name="min_controller_version" value="0.230.0"
|
||||
golden_version = 0.230.0
|
||||
agent_version = 0.130.0
|
||||
@@ -0,0 +1,130 @@
|
||||
### host: demo-hp utc: 2026-08-31T20:40:30Z local: 20:40:30 UTC
|
||||
--- controller image ---
|
||||
gitea.dooplex.hu/admin/felhom-controller:0.231.0
|
||||
--- containers ---
|
||||
bookstack Up About an hour (healthy)
|
||||
bookstack-db Up About an hour (healthy)
|
||||
calibre-web Up About an hour (healthy)
|
||||
cloudflared Up 10 days
|
||||
docmost Up About an hour (healthy)
|
||||
docmost-postgres Up About an hour (healthy)
|
||||
docmost-redis Up About an hour (healthy)
|
||||
felhom-controller Up 2 hours (healthy)
|
||||
filebrowser Up 10 days (healthy)
|
||||
kimai Up About an hour (healthy)
|
||||
kimai-db Up About an hour (healthy)
|
||||
opengist Up About an hour (healthy)
|
||||
paperless-postgres Up About an hour (healthy)
|
||||
paperless-redis Up About an hour (healthy)
|
||||
paperless-webserver Up About an hour (healthy)
|
||||
privatebin Up About an hour (healthy)
|
||||
romm Up About an hour (healthy)
|
||||
romm-db Up About an hour (healthy)
|
||||
romm-redis Up About an hour (healthy)
|
||||
traefik Up 10 days
|
||||
--- filesystems ---
|
||||
Mounted on 1B-blocks Avail Use%
|
||||
/ 33501757440 30763704320 4%
|
||||
/var/lib/felhom 73793978368 57947402240 18%
|
||||
/mnt/felhom-drives 41424257024 21560401920 46%
|
||||
/dev 503808 499712 1%
|
||||
/dev/shm 15725801472 15725801472 0%
|
||||
/run 6290321408 6254825472 1%
|
||||
/run/lock 5242880 5242880 0%
|
||||
/tmp 15725805568 15724347392 1%
|
||||
/mnt/felhom-drives/hdd_1 1006980812800 949632593920 1%
|
||||
--- tier1 primary units (sha256 per file) ---
|
||||
34160a1a1b8c2729fa0bfb71176c117c4560d36a979e128af5fca197acba6104 bookstack/compose/.felhom.yml
|
||||
5ca24eb1dfea1edaa1634585794153b0fb70682d42695ad89f878ef473764bbc bookstack/compose/app.yaml
|
||||
3ee9f76f897e1ba24ea3af8de12079d54cc483a33cad4dc8a9518916212fd090 bookstack/compose/docker-compose.yml
|
||||
452d4098db5d8d5902c30e5343395a36861851ae17c98ef77ffd09b21f1312e7 bookstack/db-dumps/bookstack-mariadb.sql
|
||||
07c6d9d44b08cbe8191671cf1c723b78b28c9186b0a2548e6014c77bfb175373 bookstack/db-dumps/pre-restore-20260822T142418Z-bookstack-mariadb.sql
|
||||
d11732109960cfa78152865d936ff921b79fc093faf19d8141ed3d80d6616c35 bookstack/db-dumps/pre-restore-20260822T162555Z-bookstack-mariadb.sql
|
||||
6c5f6bcbd2ff8bad2218bb54eab227b01ee46f067e9e356e07dc059236b4c17e bookstack/db-dumps/pre-restore-20260822T215540Z-bookstack-mariadb.sql
|
||||
e8080d28381d7df9487b58909bb47019b35badfb38d1c0681c85379b6316984e bookstack/manifest.json
|
||||
521e3efb7242b601ac291d734d120d995f3a201463bbb6bea7157fd7190d73d6 bookstack/volume-dumps/bookstack_bookstack_config.tar
|
||||
c9e6ea282d044d16a3f6fee79c59e78014a079e6255d082b81da97e5f06fd272 bookstack/volume-dumps/bookstack_bookstack_db_data.tar
|
||||
a6bd089341c6608263fcb6c7c4f8b1f803a3d72240f5a2cc34eb6fe58e0b59bd docmost/compose/.felhom.yml
|
||||
0624e0f2b81fb802c90f8ff306ad7ebcdaa720e93d94f6356079f313c84322ab docmost/compose/app.yaml
|
||||
3920e17042a2f6103abd28bcf641cc22f6d6c1850384bea1d0896826ec482496 docmost/compose/docker-compose.yml
|
||||
b29633a648ad81f3e5bf6f622de7dc674f303ade281ed8bd4cb1e9c93a749de4 docmost/db-dumps/docmost-postgres.sql
|
||||
73917ba6bc3072dfc7b5be9c6df4f8361da7e987230f5d56f7b62f397fe15ef1 docmost/db-dumps/pre-restore-20260822T162347Z-docmost-postgres.sql
|
||||
4c134c2ced74df26f49ef1910694cbbd25f2598549bb4b5bb145aac054935949 docmost/db-dumps/pre-restore-20260822T162708Z-docmost-postgres.sql
|
||||
13e5a864701966d9e4053b5bb7dd800cca3d77ebb07f4fd2f32c86389422af25 docmost/db-dumps/pre-restore-20260822T215432Z-docmost-postgres.sql
|
||||
ac7efa388d07d13d51daaf78d1695f097eb7232d0d37d24e72b6700043df80ae docmost/manifest.json
|
||||
992756063e34a8b4c4536c3c0ae7e031d723f5a7a22a47edffaf7afb5496d269 docmost/volume-dumps/docmost_docmost_postgres_data.tar
|
||||
43db53aad10a0af5ef2d9377e57ed135e68eb2a0c2a14791f89f81a6de17171d docmost/volume-dumps/docmost_docmost_redis_data.tar
|
||||
5c3dd6b53c6c6478d67236fbf6e60babe4f35ad5bc2f16127dfcb6463bd2034a docmost/volume-dumps/docmost_docmost_storage.tar
|
||||
95beb458a42391af4bf78429decfbc60537d8d53d61bea68c38687bcc7fa0d23 kimai/compose/.felhom.yml
|
||||
9192dec10e5aae76c2787d0e82ad39115d43f7011519f854bc06534f930c3e9c kimai/compose/app.yaml
|
||||
c25029f8bd16e6252dceda0b4e87917a8b9ce0b9ad6bdbfc82fa8d4f630e6310 kimai/compose/docker-compose.yml
|
||||
a8cf3c54894861593656fff2e35ac66e24c69b525868e58d3fa14d72f563b51a kimai/db-dumps/kimai-mariadb.sql
|
||||
5c6ce6f6b098c9ddb32c5e0d774ac2b81c634d45b1f5d75e7e5a969927aabc4c kimai/manifest.json
|
||||
58d76e783eca2dc8b622f33f7e1424c42e5088065150e9b99bbc7f3db24aee43 kimai/volume-dumps/kimai_kimai_db_data.tar
|
||||
db18ea11bd19a1acc816d60e8e733dc7abb8162b3dbd91cdd7dab9f999862ac1 kimai/volume-dumps/kimai_kimai_var.tar
|
||||
a6d944d52b6ff021bf7a09736a90eeea760b605904fe8a591a7229a791ef5ff8 opengist/compose/.felhom.yml
|
||||
c6f1f35935c4edd918fac809eebbe1f8ebd6a9a704bbdb8ac4b39c623790f072 opengist/compose/app.yaml
|
||||
a44845f6db193c2b1127b3781f7c19a9051b2ebe2c924a3a5f17e6c82d02c513 opengist/compose/docker-compose.yml
|
||||
f3234cf0a342ddc521953771978f36c34465ece360513fe54dc36513b53ac3a3 opengist/manifest.json
|
||||
69ccb3e55f366df083990bfd85ea3113d64d64f557f1a648ee8a44d6c618ea9f opengist/volume-dumps/opengist_opengist_data.tar
|
||||
936220c684a0a220ea5ee3265c1ef6703b3e769129056fc8ad55bd2bd31a42fa paperless/db-dumps/paperless-postgres.sql
|
||||
65cf6407b07f0f8e258261494f7141d747e75ac8cd16ffbe5b6941d90baaef4f privatebin/compose/.felhom.yml
|
||||
3838f4b2e39d7d9ea51397323df43e9fcd762db1b82b880b94e5b20cc88e188f privatebin/compose/app.yaml
|
||||
ac56509d5f5c93b844608a64618dea14a67d1e2986dedd3a03e14d867e9189e5 privatebin/compose/docker-compose.yml
|
||||
e29789faa9834396f4351618e290f8e33ff1cd2faa44f58e32ab51d7bbcb1c2d privatebin/manifest.json
|
||||
c3ea1bae0731bcc3082d6c94bfd91aa66e2332c191c0d96c14341f80c9a7e3bc privatebin/volume-dumps/privatebin_privatebin_data.tar
|
||||
6ee3b29f856e2b464b86098687feda3811a225cb4272ffbe3538741748ee87b5 calibre-web/compose/.felhom.yml
|
||||
1a3b1e818fb3ddfd7e25fb5a75557629b743a0db39efad51c1f11d7e3ec6e593 calibre-web/compose/app.yaml
|
||||
295cee174968d54b393840e91fb6d2b43472f423800f9e9388bf90a47574a1a7 calibre-web/compose/docker-compose.yml
|
||||
64e8ebf5bc420d7ce82e19843db6e492a3d16ab9d41cd4fe6df030e257bd9dbd calibre-web/manifest.json
|
||||
0f10d958ad1ebfc32b47f65d5801138e1393c634f81b7ad2270d8f4ef6400add calibre-web/volume-dumps/calibre-web_calibre_web_config.tar
|
||||
a7cce0a557fd151e6385a137f4721366dd2cd0aa3876783f0f9f0acc9a78dd23 paperless-ngx/compose/.felhom.yml
|
||||
8dfec452dfc00c7e3dce26864bf97165acac44f32470d2425c96e2bd86649cf0 paperless-ngx/compose/app.yaml
|
||||
b112952565ef3928f192358ea58fdf4a5a26d788593bf2614e36050c77539b3d paperless-ngx/compose/docker-compose.yml
|
||||
d218dd7265c4c5071b417ca94824a1045454f667346ab6dfbb52325a22408811 paperless-ngx/db-dumps/paperless-ngx-postgres.sql
|
||||
6f257d094a6506ecce39ec4103a303e4901a45587013143e31adb887de46d1df paperless-ngx/db-dumps/pre-restore-20260822T075658Z-paperless-ngx-postgres.sql
|
||||
08981f1306cb811268f2e4d8b65b53b48a818a5804e1780a7424c6c3320cbfff paperless-ngx/manifest.json
|
||||
e6d9fcbac4c9675051e1a1fcc83b0a65ff34360b4cf20de397457858daa9bcd3 paperless-ngx/volume-dumps/paperless-ngx_paperless_data.tar
|
||||
4103ecd30e09c00613ba9e110e53d6aff863ca287a186f6b4778fed75f892fdc paperless-ngx/volume-dumps/paperless-ngx_paperless_postgres_data.tar
|
||||
dc9ae65ec63107d607d56a40bd309006fbe847481bc34303fc7bcc41894c8cd5 paperless-ngx/volume-dumps/paperless-ngx_paperless_redis_data.tar
|
||||
8384f570a4d6dd289d5b9ac1061e569e21c8f265d417108fc9d4eb187f5fb3bc romm/compose/.felhom.yml
|
||||
39a4318467ad8945866ac83a9f6a191a91d25330c8bbe873117ab67be3e2ae00 romm/compose/app.yaml
|
||||
c673113e354a4a407f523dcfc3afe780773ec6e495fe5a76d7466b840d0b1fbb romm/compose/docker-compose.yml
|
||||
ecfcc45c330c04d59e639592154af84d25256257be3a6f98dc383cfe2f1e1503 romm/db-dumps/pre-restore-20260821T210246Z-romm-mariadb.sql
|
||||
7869803afb82300d36f86a793b45b5379c73f8165d448def0938520c184c20dd romm/db-dumps/romm-mariadb.sql
|
||||
bce34837987be85ddf969ad9a04f0cb748789cfd9a2b8e6ea5124d0ae0eab890 romm/manifest.json
|
||||
ba4425e00463cd8deefc1ba9aadaccb32acc99585384f6536c5fb5675678917e romm/volume-dumps/romm_romm_config.tar
|
||||
d43535c361ddd5e8444184f10cf2dabfe4e0996982c19851c6f3de8fa5d067b9 romm/volume-dumps/romm_romm_db_data.tar
|
||||
c387fda2c11d090d2a7069bad71b70b3d8e85eed52ea3ce6c1d3edaaff921e4e romm/volume-dumps/romm_romm_redis_data.tar
|
||||
--- tier2 secondary ---
|
||||
files: 43
|
||||
bytes: 502415341 /mnt/felhom-drives/hdd_1/backups/secondary
|
||||
files: 46
|
||||
bytes: 274676046 /mnt/sys_drive/felhom-data/backups/secondary
|
||||
--- scheduler jobs registered ---
|
||||
Daily job db-dump scheduled for 2026-09-01 02:30 CEST
|
||||
Daily job fill-watch scheduled for 2026-09-01 03:30 CEST
|
||||
Daily job metrics-prune scheduled for 2026-09-01 04:00 CEST
|
||||
Daily job offbox-backup scheduled for 2026-09-01 04:15 CEST
|
||||
Daily job offsite-abandon-sweep scheduled for 2026-09-01 05:10 CEST
|
||||
Daily job offsite-integrity scheduled for 2026-09-01 06:00 CEST
|
||||
Daily job offsite-proof scheduled for 2026-09-01 05:30 CEST
|
||||
Daily job tier2-backup scheduled for 2026-09-01 03:30 CEST
|
||||
--- offsite state ---
|
||||
enabled True
|
||||
schedule 'daily'
|
||||
last_run '2026-08-31T19:25:12Z'
|
||||
last_success '2026-08-31T19:25:12Z'
|
||||
last_status 'ok'
|
||||
last_duration '2m48s'
|
||||
snapshot_count 67
|
||||
repo_size_bytes 145868697
|
||||
stats_known True
|
||||
last_integrity_check '2026-08-31T19:12:51Z'
|
||||
last_integrity_ok True
|
||||
last_integrity_depth '100%'
|
||||
last_proof_run '2026-08-31T19:25:52Z'
|
||||
last_proof_stack 'opengist'
|
||||
last_proof_snapshot 'ea94dae0'
|
||||
last_proof_result 'pass'
|
||||
proved_snapshots {'bookstack': 'efb67a11', 'calibre-web': '996d6e7e', 'docmost': '180c5933', 'kimai': '3c11059b', 'opengist': 'ea94dae0'}
|
||||
@@ -0,0 +1,52 @@
|
||||
### host: demo-felhom utc: 2026-08-31T20:40:32Z local: 20:40:32 UTC
|
||||
--- controller image ---
|
||||
gitea.dooplex.hu/admin/felhom-controller:0.230.0
|
||||
--- containers ---
|
||||
cloudflared Up 3 weeks
|
||||
felhom-controller Up 6 hours (healthy)
|
||||
filebrowser Up 3 weeks (healthy)
|
||||
opengist Up 17 hours (healthy)
|
||||
traefik Up 3 weeks
|
||||
--- filesystems ---
|
||||
Mounted on 1B-blocks Avail Use%
|
||||
/ 33501757440 30776147968 4%
|
||||
/var/lib/felhom 264027389952 246366150656 2%
|
||||
/mnt/felhom-drives 100861726720 66319564800 31%
|
||||
/dev 503808 499712 1%
|
||||
/dev/shm 8269164544 8269164544 0%
|
||||
/run 3307667456 3298725888 1%
|
||||
/run/lock 5242880 5242880 0%
|
||||
/tmp 8269164544 8269099008 1%
|
||||
--- tier1 primary units (sha256 per file) ---
|
||||
a6d944d52b6ff021bf7a09736a90eeea760b605904fe8a591a7229a791ef5ff8 opengist/compose/.felhom.yml
|
||||
285094cd80d13b391a14f76be94b5f05f05e83cbc66cb2758f6f550f75c51769 opengist/compose/app.yaml
|
||||
a44845f6db193c2b1127b3781f7c19a9051b2ebe2c924a3a5f17e6c82d02c513 opengist/compose/docker-compose.yml
|
||||
d01bb9f6a80d644d3599350f7ccb2bd3c42691737975bb780ca0b1dbdb251461 opengist/manifest.json
|
||||
aba17a796b637c5ac23f1d9eadcd6226cf6280478c320dafa3c306bc1490587b opengist/volume-dumps/opengist_opengist_data.tar
|
||||
--- tier2 secondary ---
|
||||
--- scheduler jobs registered ---
|
||||
Daily job db-dump scheduled for 2026-09-01 02:30 CEST
|
||||
Daily job fill-watch scheduled for 2026-09-01 03:30 CEST
|
||||
Daily job metrics-prune scheduled for 2026-09-01 04:00 CEST
|
||||
Daily job offbox-backup scheduled for 2026-09-01 04:15 CEST
|
||||
Daily job offsite-abandon-sweep scheduled for 2026-09-01 05:10 CEST
|
||||
Daily job offsite-integrity scheduled for 2026-09-01 06:00 CEST
|
||||
Daily job tier2-backup scheduled for 2026-09-01 03:30 CEST
|
||||
--- offsite state ---
|
||||
enabled True
|
||||
schedule 'daily'
|
||||
last_run '2026-08-31T02:15:46Z'
|
||||
last_success '2026-08-31T02:15:46Z'
|
||||
last_status 'ok'
|
||||
last_duration '41s'
|
||||
snapshot_count 10
|
||||
repo_size_bytes 135661
|
||||
stats_known True
|
||||
last_integrity_check '2026-08-31T04:00:00Z'
|
||||
last_integrity_ok True
|
||||
last_integrity_depth '<ABSENT>'
|
||||
last_proof_run '<ABSENT>'
|
||||
last_proof_stack '<ABSENT>'
|
||||
last_proof_snapshot '<ABSENT>'
|
||||
last_proof_result '<ABSENT>'
|
||||
proved_snapshots '<ABSENT>'
|
||||
@@ -0,0 +1,5 @@
|
||||
=== hand-deploy 0.231.0 to demo-felhom (reversible; the golden bake later supersedes it) ===
|
||||
deployed
|
||||
--- verify ---
|
||||
gitea.dooplex.hu/admin/felhom-controller:0.231.0 Up 26 seconds (healthy)
|
||||
--- the new job must now be registered ---
|
||||
@@ -0,0 +1,14 @@
|
||||
=== every Daily job registered on demo-felhom after the 0.231.0 restart ===
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job db-dump scheduled for 2026-09-01 02:30 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job tier2-backup scheduled for 2026-09-01 03:30 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job offbox-backup scheduled for 2026-09-01 04:15 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job offsite-abandon-sweep scheduled for 2026-09-01 05:10 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job offsite-integrity scheduled for 2026-09-01 06:00 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job offsite-proof scheduled for 2026-09-01 05:30 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job metrics-prune scheduled for 2026-09-01 04:00 CEST
|
||||
2026/08/31 20:40:48 [INFO] [scheduler] Daily job fill-watch scheduled for 2026-09-01 03:30 CEST
|
||||
|
||||
=== POSITIVE CONTROL: the same grep on demo-hp, which is known to have it ===
|
||||
25
|
||||
=== NEGATIVE CONTROL: a string that cannot be there ===
|
||||
0
|
||||
@@ -0,0 +1,21 @@
|
||||
=== cycle recorder on demo-felhom: a FOLLOW stream, not a sampler ===
|
||||
(one exec that streams every line, so there are no sampling gaps; the full docker log is
|
||||
collected again at Phase 6 as the authoritative belt-and-braces record)
|
||||
recorder pid-ish started; bytes so far: 11712
|
||||
|
||||
=== POSITIVE CONTROL: a line that MUST appear (the startup banner already in the log) ===
|
||||
0
|
||||
=== NEGATIVE CONTROL: a line that cannot appear ===
|
||||
0
|
||||
=== what the recorder actually holds (first and last lines) ===
|
||||
perl: warning: Setting locale failed.
|
||||
perl: warning: Please check that your locale settings:
|
||||
...
|
||||
2026-08-31T20:41:58.364422057Z 2026/08/31 20:41:58 [INFO] [stacks] Status refresh: 4 containers across 56 stacks
|
||||
2026-08-31T20:42:08.363891005Z 2026/08/31 20:42:08 [INFO] [stacks] Status refresh: 4 containers across 56 stacks
|
||||
bytes: 11825
|
||||
|
||||
=== the positive control failed because I picked a HUB line. Re-control on a line the CONTROLLER really logs: ===
|
||||
scheduler hits=24
|
||||
Daily job hits=8
|
||||
felhom hits=15
|
||||
@@ -0,0 +1,35 @@
|
||||
# Phase 1 — the R-408 hazard, live. VERDICT: **FAIL (the hazard is real and reachable)**
|
||||
|
||||
**The customer-facing consequence is CONTAINED. The hazard itself is not.**
|
||||
|
||||
## What was established, all measured through the product's own endpoints
|
||||
|
||||
| # | fact | how |
|
||||
|---|---|---|
|
||||
| 1 | **`restic stats` takes a repository lock** in 0.14.0 | clean-room: nothing else running, 4× `stats`, sampler read `locks=1` (`11-stats-locks-cleanroom.txt`) |
|
||||
| 2 | A customer **full**-restore runs `stats` in its preparation, so it holds a lock while holding **no** `acquireRunning` | `09-escalation-window.txt`, 20:50:29 |
|
||||
| 3 | The integrity check is therefore **not blocked** by a running restore and starts | `06-reverse.txt`, `skipped:false` |
|
||||
| 4 | It meets the lock and **`resticStep` escalates to `unlock --remove-all`** | `07-…txt` 20:50:31 + the sampler caught **`restore …` and `unlock --remove-all` in the SAME sample** at 20:50:51 |
|
||||
| 5 | The log calls it *"a stale exclusive lock left by a previous crash"* — **there was no crash** | `07-…txt` |
|
||||
| 6 | The check then could not verify the store; classified **Unreachable, NOT damage** → **no alarm, no customer mail**, due-ness not advanced | `07-…txt` 20:50:36 |
|
||||
|
||||
## The opposite direction is FENCED — and that was measured, not assumed
|
||||
|
||||
Five restores fired into a running check at **5 / 15 / 25 / 35 / 40 s** offsets were **all refused**
|
||||
by `restoreOpBlocked` (`offbox_handlers.go:358`), and **zero** restic processes were sampled. So the
|
||||
hazard is reachable **only restore-first**. All five checks completed `ok:true` (39–52 s).
|
||||
|
||||
## A third pairing, same root cause
|
||||
|
||||
The new R-87 proof **skips** correctly when the integrity check holds the flag
|
||||
(`skipped:true`), and **runs** during a customer restore (`stack:paperless-ngx`, `verdict:pass`) —
|
||||
because the restore holds no flag. Harmless (the proof uses `--no-lock` and never `unlockStale`), but
|
||||
it is the same missing-flag consequence in a third place.
|
||||
|
||||
## Instruments
|
||||
|
||||
The lock sampler was **proven before any zero was believed**: `locks=0` while quiet, then **8
|
||||
consecutive `locks=1` samples** across a real 43.9 s integrity check. Negative control: a string that
|
||||
cannot appear returned 0.
|
||||
|
||||
**Filed as R-411.** Nothing was fixed (runbook §2.6).
|
||||
+10
@@ -0,0 +1,10 @@
|
||||
=== QUIET PERIOD: the sampler must report 0 ===
|
||||
20:43:04 locks=0
|
||||
20:43:09 locks=0
|
||||
|
||||
=== POSITIVE CONTROL: integrity check at 100% depth, which holds a lock (R-407) ===
|
||||
|
||||
[http=200 wall=43.938650s]
|
||||
|
||||
=== the sampler must have SEEN it ===
|
||||
8
|
||||
+30
@@ -0,0 +1,30 @@
|
||||
--- offset 5s, app opengist ---
|
||||
t_check_start=20:44:40
|
||||
t_restore_fire=20:44:45
|
||||
[http=302 wall=0.010464s]
|
||||
check result: "duration_ms":47969 "ok":true skip_reason":"" "ok":true
|
||||
t_done=20:45:31
|
||||
--- offset 15s, app opengist ---
|
||||
t_check_start=20:45:39
|
||||
t_restore_fire=20:45:54
|
||||
[http=302 wall=0.010480s]
|
||||
check result: "duration_ms":46798 "ok":true skip_reason":"" "ok":true
|
||||
t_done=20:46:28
|
||||
--- offset 25s, app opengist ---
|
||||
t_check_start=20:46:36
|
||||
t_restore_fire=20:47:01
|
||||
[http=302 wall=0.009711s]
|
||||
check result: "duration_ms":39571 "ok":true skip_reason":"" "ok":true
|
||||
t_done=20:47:18
|
||||
--- offset 35s, app opengist ---
|
||||
t_check_start=20:47:26
|
||||
t_restore_fire=20:48:01
|
||||
[http=302 wall=0.009626s]
|
||||
check result: "duration_ms":52246 "ok":true skip_reason":"" "ok":true
|
||||
t_done=20:48:21
|
||||
--- offset 40s, app opengist ---
|
||||
t_check_start=20:48:29
|
||||
t_restore_fire=20:49:09
|
||||
[http=302 wall=0.009946s]
|
||||
check result: "duration_ms":39165 "ok":true skip_reason":"" "ok":true
|
||||
t_done=20:49:11
|
||||
@@ -0,0 +1,58 @@
|
||||
20:44:37 locks=0
|
||||
20:44:43 locks=0 | restic -r <REPO> -o <CMD> cat config
|
||||
20:44:48 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:44:53 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:44:58 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:03 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:08 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:14 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:19 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:24 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:29 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:34 locks=0
|
||||
20:45:39 locks=0 | restic -r <REPO> -o <CMD> cat config
|
||||
20:45:45 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:50 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:45:55 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:00 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:05 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:11 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:16 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:21 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:26 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:31 locks=0
|
||||
20:46:36 locks=0
|
||||
20:46:42 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:47 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:52 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:46:57 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:02 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:08 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:13 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:18 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:23 locks=0
|
||||
20:47:28 locks=0 | restic -r <REPO> -o <CMD> cat config
|
||||
20:47:33 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:39 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:44 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:49 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:54 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:47:59 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:05 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:10 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:15 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:21 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:26 locks=0
|
||||
20:48:31 locks=0 | restic -r <REPO> -o <CMD> cat config
|
||||
20:48:37 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:42 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:47 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:52 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:48:58 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:49:03 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:49:08 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:49:13 locks=0
|
||||
20:49:18 locks=0
|
||||
20:49:24 locks=0
|
||||
20:49:29 locks=0
|
||||
20:49:34 locks=0
|
||||
@@ -0,0 +1,10 @@
|
||||
=== DID THE UNLOCK ESCALATION EVER FIRE? ===
|
||||
'unlock --remove-all' in any argv: 0
|
||||
plain 'unlock' in any argv: 0
|
||||
|
||||
=== DID A LOCK EVER VANISH WHILE A CHECK WAS STILL RUNNING? ===
|
||||
samples: 58 with a lock: 43
|
||||
lock-vanished-under-a-live-check events: 0
|
||||
samples showing restore AND check running together: 0
|
||||
|
||||
=== a sample of the overlap, verbatim ===
|
||||
+12
@@ -0,0 +1,12 @@
|
||||
2026/08/31 20:45:54 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/restore
|
||||
2026/08/31 20:45:54 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/restore from 172.18.0.4:41142
|
||||
2026/08/31 20:45:54 offbox_handlers.go:358: [WARN] [web] off-box restore refused for opengist (mode=unit): another backup/restore op is already running
|
||||
2026/08/31 20:47:01 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/restore
|
||||
2026/08/31 20:47:01 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/restore from 172.18.0.4:41142
|
||||
2026/08/31 20:47:01 offbox_handlers.go:358: [WARN] [web] off-box restore refused for opengist (mode=unit): another backup/restore op is already running
|
||||
2026/08/31 20:48:01 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/restore
|
||||
2026/08/31 20:48:01 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/restore from 172.18.0.4:41142
|
||||
2026/08/31 20:48:01 offbox_handlers.go:358: [WARN] [web] off-box restore refused for opengist (mode=unit): another backup/restore op is already running
|
||||
2026/08/31 20:49:09 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/restore
|
||||
2026/08/31 20:49:09 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/restore from 172.18.0.4:41142
|
||||
2026/08/31 20:49:09 offbox_handlers.go:358: [WARN] [web] off-box restore refused for opengist (mode=unit): another backup/restore op is already running
|
||||
@@ -0,0 +1,12 @@
|
||||
--- reverse: restore(kimai,full) then check +1s ---
|
||||
t_restore=20:50:26
|
||||
[http=302 wall=0.009338s]
|
||||
t_check=20:50:27
|
||||
"duration_ms":6716 "ok":false "skip_reason":"" "skipped":false "ok":true
|
||||
t_done=20:50:36
|
||||
--- reverse: restore(kimai,full) then check +2s ---
|
||||
t_restore=20:50:42
|
||||
[http=302 wall=0.011104s]
|
||||
t_check=20:50:44
|
||||
"duration_ms":43543 "ok":true "skip_reason":"" "skipped":false "ok":true
|
||||
t_done=20:51:30
|
||||
+14
@@ -0,0 +1,14 @@
|
||||
2026/08/31 20:50:26 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/restore
|
||||
2026/08/31 20:50:26 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/restore from 172.18.0.4:42330
|
||||
2026/08/31 20:50:27 auth.go:134: [DEBUG] [web] auth: valid session for POST /api/debug/backup/integrity
|
||||
2026/08/31 20:50:31 offbox.go:766: [WARN] [offbox] cleared a stale exclusive lock left by a previous crash (single-writer repo) before integrity-check; retrying once
|
||||
2026/08/31 20:50:36 offbox_integrity.go:325: [WARN] [offbox] integrity: the check could not run to a verdict (other) — NOT reported as damage: exit status 1: using temporary cache in /tmp/restic-check-cache-753555912
|
||||
2026/08/31 20:50:42 auth.go:134: [DEBUG] [web] auth: valid session for POST /backup/offbox/restore
|
||||
2026/08/31 20:50:42 server.go:393: [DEBUG] [web] ServeHTTP: POST /backup/offbox/restore from 172.18.0.4:42330
|
||||
2026/08/31 20:50:42 offbox_handlers.go:358: [WARN] [web] off-box restore refused for kimai (mode=full): another backup/restore op is already running
|
||||
2026/08/31 20:50:44 auth.go:134: [DEBUG] [web] auth: valid session for POST /api/debug/backup/integrity
|
||||
2026/08/31 20:50:49 offbox.go:766: [WARN] [offbox] cleared a stale exclusive lock left by a previous crash (single-writer repo) before integrity-check; retrying once
|
||||
2026/08/31 20:51:30 offbox_integrity.go:306: [INFO] [offbox] integrity: check PASSED in 44s (structure, index, and 100% of the pack data re-read)
|
||||
2026/08/31 20:51:30 notifier.go:206: [DEBUG] PushEvent: type=backup_integrity_ok severity=info url=https://hub.felhom.eu/api/v1/event
|
||||
2026/08/31 20:51:30 notifier.go:232: [DEBUG] PushEvent: backup_integrity_ok pushed OK (HTTP 200)
|
||||
2026/08/31 20:51:30 notifier.go:234: [INFO] Event pushed: backup_integrity_ok (info) — A távoli mentés ellenőrzése rendben lezajlott. (44s, a mentett adatok 100%-át újraolvasva)
|
||||
+20
@@ -0,0 +1,20 @@
|
||||
20:50:24 locks=0 | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:29 locks=1 | restic -r <REPO> -o <CMD> list locks --no-lock | restic -r <REPO> -o <CMD> stats 3c11059b --json
|
||||
20:50:35 locks=0 | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:40 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:45 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> cat config | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:51 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> unlock --remove-all | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:56 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:01 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:06 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:12 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:17 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:22 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:28 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:33 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:39 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:44 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:49 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:51:55 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:52:00 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:52:05 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
+7
@@ -0,0 +1,7 @@
|
||||
=== sampler across the 20:50:26 restore and the 20:50:27 check ===
|
||||
20:50:24 locks=0 | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:29 locks=1 | restic -r <REPO> -o <CMD> list locks --no-lock | restic -r <REPO> -o <CMD> stats 3c11059b --json
|
||||
20:50:35 locks=0 | restic -r <REPO> -o <CMD> check --read-data-subset=100% | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <R
|
||||
20:50:40 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> list locks --no-lock
|
||||
20:50:45 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> cat config | restic -r <REPO> -o <CMD> list
|
||||
20:50:51 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> unlock --remove-all | restic -r <REPO> -o <C
|
||||
@@ -0,0 +1,7 @@
|
||||
=== DOES restic stats TAKE A LOCK? run it alone, 4x back to back ===
|
||||
stats-done
|
||||
20:52:38 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | r
|
||||
20:52:44 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | s
|
||||
20:52:49 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | s
|
||||
20:52:54 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | r
|
||||
20:53:00 locks=0 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai
|
||||
+7
@@ -0,0 +1,7 @@
|
||||
settled: locks=0 after ~10s
|
||||
=== CLEAN-ROOM: nothing else running. 4x restic stats, tight watch ===
|
||||
done
|
||||
20:53:25 locks=0 | sh -c . /tmp/soak-env.sh; restic -r "$REPO" -o "$SFTPCMD" list locks --no-lock 2>/dev/null | grep -c
|
||||
20:53:31 locks=1 | sh -c . /tmp/soak-env.sh; for i in 1 2 3 4; do restic -r "$REPO" -o "$SFTPCMD" stats 3c11059b --json
|
||||
20:53:36 locks=0 | sh -c . /tmp/soak-env.sh; for i in 1 2 3 4; do restic -r "$REPO" -o "$SFTPCMD" stats 3c11059b --json
|
||||
20:53:41 locks=0
|
||||
+5
@@ -0,0 +1,5 @@
|
||||
=== A. proof INTO a running integrity check (the check holds acquireRunning) ===
|
||||
skip_reason":"a backup or restore is already running skipped":true verdict":"
|
||||
|
||||
=== B. proof INTO a running customer restore (the restore holds NO acquireRunning) ===
|
||||
skip_reason":" skipped":false stack":"paperless-ngx verdict":"pass
|
||||
@@ -0,0 +1,17 @@
|
||||
20:54:36 locks=0
|
||||
20:54:41 locks=0 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:54:47 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:54:52 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:54:58 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:55:03 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:55:08 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:55:14 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:55:19 locks=1 | restic -r <REPO> -o <CMD> check --read-data-subset=100%
|
||||
20:55:25 locks=1 | restic -r <REPO> -o <CMD> stats 3c11059b --json | restic -r <REPO> -o <CMD> snapshots latest --tag calibre-web --json
|
||||
20:55:30 locks=1 | restic -r <REPO> -o <CMD> restore 3c11059b --target /mnt/felhom-drives/hdd_1/backups/offsite-restore/kimai | restic -r <REPO> -o <CMD> snapshots latest --tag kimai --json
|
||||
20:55:35 locks=0 | restic -r <REPO> -o <CMD> snapshots latest --tag paperless-ngx --json
|
||||
20:55:41 locks=0 | restic -r <REPO> -o <CMD> restore bca92384 --target /mnt/felhom-drives/hdd_1/backups/offsite-proof/paperless-ngx --include /mnt/felhom-drives/hdd_1/ba
|
||||
20:55:46 locks=0
|
||||
20:55:52 locks=0
|
||||
20:55:57 locks=0
|
||||
20:56:02 locks=0
|
||||
@@ -0,0 +1,44 @@
|
||||
# Phase 2 — the new guards against each other. VERDICT: **FAIL (one real defect found)**
|
||||
|
||||
Five of six sub-tests ran; 2.6 needs Phase 4's app and is deferred there.
|
||||
|
||||
| # | test | verdict | one sentence |
|
||||
|---|---|---|---|
|
||||
| 2.1 | rehydrate vs capture | **FAIL — R-412** | the capture won, and rebuilt the primary **hollow**: 185 664 B → 4 382 B, `volume_dumps: None` |
|
||||
| 2.2 | rehydrate then mirror | **PASS (partial)** | the secondary survived byte-identical (`3e26592f…`), but the mirror run did not target this app, so R-403's guard was **not** exercised — deferred to Phase 5's 03:30 job, which is the natural test |
|
||||
| 2.3 | stale scratch marker | **PASS** | a planted `deadbeef / full:true / 2020` marker was fully replaced by `180c5933 / full:false / now` |
|
||||
| 2.4 | two restores at once | **PASS** | exactly one refusal, exactly one completion |
|
||||
| 2.5 | proof during other runs | **PASS, with the runbook's premise corrected** | see below |
|
||||
| 2.6 | legitimately-empty unit | deferred to Phase 4 | no such app exists on the box yet |
|
||||
|
||||
## The defect — R-412, and it is the natural instance of R-403's shape
|
||||
|
||||
I removed `opengist`'s primary unit. The 5-minute capture rebuilt it with compose and manifest and
|
||||
**no volume tar**; the off-site backup then pushed that hollow unit and logged
|
||||
`backed up opengist (… 0 mandatory path(s))` — **a success line over a backup holding none of the
|
||||
app's data**. The newest off-site snapshot `35ba9fe7` is hollow.
|
||||
|
||||
**The capture is not wrong in isolation** — R-403 deliberately refused to guard it, because a capture
|
||||
describing an empty tree as empty is correct. What is wrong is that **nothing between the capture and
|
||||
the push notices a unit that had dumps yesterday and has none today.**
|
||||
|
||||
## And then the thing that makes tonight worth it — R-413
|
||||
|
||||
The R-87 proof, rotating normally, reached `opengist` and returned **`verdict:"fail"`,
|
||||
`volumes_expected_none_captured: opengist_data`**, with one `offsite_proof_empty` at severity `error`.
|
||||
The four apps ahead of it in the rotation all passed. **Yesterday's session had to hand-build its
|
||||
failing case and declare it; tonight the product produced one by itself and the guard caught it.**
|
||||
|
||||
## 2.5 — the runbook's premise was wrong, and the behaviour is right
|
||||
|
||||
The runbook expected the proof to skip during a Tier-2 run. **It did not skip** (`stack:privatebin`,
|
||||
`verdict:pass`, due-ness advanced 6→7). Established rather than assumed: `RunTier2` contains **zero**
|
||||
`acquireRunning` calls and **zero** references to restic — it is a purely local rsync mirror that
|
||||
cannot collide with the repository. The proof correctly skipped during the **off-site backup**
|
||||
(`skipped:true`, due-ness held at 7), which is the operation that does share the repo.
|
||||
|
||||
## Deliberately left in place
|
||||
|
||||
`opengist` stays hollow-primary / complete-secondary overnight. That is **exactly** Phase 5's first
|
||||
injected fault, and letting the real 03:30 `tier2-backup` meet it is a better test than forcing one.
|
||||
Restored in Phase 7. Its live app data is untouched and healthy throughout.
|
||||
+7
@@ -0,0 +1,7 @@
|
||||
=== 2.4 TWO RESTORES AT ONCE (direct POST, back to back) ===
|
||||
--- the log must show ONE start and ONE refusal ---
|
||||
off-box restore refused for bookstack (mode=unit): another backup/restore op is already running
|
||||
off-box restore docmost completed (full=false, async)
|
||||
|
||||
scratch dirs created (exactly one app expected):
|
||||
bookstack calibre-web docmost kimai paperless-ngx
|
||||
+12
@@ -0,0 +1,12 @@
|
||||
=== 2.3 STALE SCRATCH MARKER (R-358) - retry, plant written from a file this time ===
|
||||
planted:
|
||||
{"schema":1,"snapshot_id":"deadbeef","full":true,"finished_at":"2020-01-01T00:00:00Z"}
|
||||
--- POSITIVE CONTROL: the assertions must SEE the planted values ---
|
||||
control ok: grep finds the planted id
|
||||
control ok: grep finds full:true
|
||||
--- run a UNIT restore (full=false) ---
|
||||
after:
|
||||
{"schema":1,"snapshot_id":"180c5933","full":false,"finished_at":"2026-08-31T20:58:24Z"}--- assertions ---
|
||||
PASS: stale id cleared
|
||||
PASS: full:false - a unit restore does not advertise a full scratch
|
||||
PASS: timestamp rewritten
|
||||
+13
@@ -0,0 +1,13 @@
|
||||
=== 2.5a PROOF DURING A TIER-2 RUN ===
|
||||
due-ness before:
|
||||
proved=6 last=paperless-ngx/bca92384
|
||||
"skip_reason":"" "skipped":false "stack":"privatebin" "verdict":"pass"
|
||||
due-ness after:
|
||||
proved=7 last=privatebin/b065197a
|
||||
|
||||
=== 2.5b PROOF DURING AN OFF-SITE BACKUP ===
|
||||
due-ness before:
|
||||
proved=7 last=privatebin/b065197a
|
||||
"skip_reason":"a backup or restore is already running" "skipped":true "stack":"" "verdict":""
|
||||
due-ness after:
|
||||
proved=7 last=privatebin/b065197a
|
||||
+26
@@ -0,0 +1,26 @@
|
||||
=== which apps have a Tier-2 (secondary) copy? ===
|
||||
root: /mnt/felhom-drives/hdd_1/backups/secondary
|
||||
bookstack
|
||||
docmost
|
||||
kimai
|
||||
opengist
|
||||
privatebin
|
||||
root: /mnt/sys_drive/felhom-data/backups/secondary
|
||||
calibre-web
|
||||
paperless-ngx
|
||||
romm
|
||||
|
||||
=== opengist primary + secondary contents ===
|
||||
/mnt/sys_drive/felhom-data/backups/primary/opengist
|
||||
1750 compose/.felhom.yml
|
||||
287 compose/app.yaml
|
||||
1260 compose/docker-compose.yml
|
||||
1119 manifest.json
|
||||
181248 volume-dumps/opengist_opengist_data.tar
|
||||
/mnt/felhom-drives/hdd_1/backups/secondary/opengist
|
||||
1 .felhom-tier2-layout
|
||||
1750 recovery-unit/compose/.felhom.yml
|
||||
287 recovery-unit/compose/app.yaml
|
||||
1260 recovery-unit/compose/docker-compose.yml
|
||||
1119 recovery-unit/manifest.json
|
||||
181248 recovery-unit/volume-dumps/opengist_opengist_data.tar
|
||||
+29
@@ -0,0 +1,29 @@
|
||||
=== 2.1/2.2 REHYDRATE vs CAPTURE vs MIRROR (opengist) ===
|
||||
BEFORE:
|
||||
primary : 5 files, 185664 bytes
|
||||
secondary: 6 files, 185665 bytes
|
||||
secondary tar sha: 3e26592f4abddd75b1b40c02
|
||||
|
||||
--- DESTROY the primary unit (the R-102 starting state) ---
|
||||
primary exists: NO
|
||||
|
||||
--- fire the R-102 Tier-2 unit-restore, and a Tier-2 MIRROR into it 2s later ---
|
||||
"count":3 "ok":true <- mirror fired during the restore
|
||||
unit-restore http: http=302
|
||||
|
||||
AFTER:
|
||||
primary : 4 files, 4382 bytes
|
||||
secondary: 6 files, 185665 bytes
|
||||
--- is the SECONDARY still complete? (the R-403 question) ---
|
||||
secondary tar sha: 3e26592f4abddd75b1b40c02
|
||||
--- is the PRIMARY sound? ---
|
||||
1750 compose/.felhom.yml
|
||||
287 compose/app.yaml
|
||||
1260 compose/docker-compose.yml
|
||||
1085 manifest.json
|
||||
--- the log ---
|
||||
auth: valid session for POST /backup/tier2/unit-restore
|
||||
ServeHTTP: POST /backup/tier2/unit-restore from 172.18.0.4:60420
|
||||
Tier 2 copied calibre-web → /mnt/sys_drive/felhom-data/backups/secondary/calibre-web (5.6 MB, 1 leg(s), 0s) [SSD: state-only]
|
||||
Tier 2 copied paperless-ngx → /mnt/sys_drive/felhom-data/backups/secondary/paperless-ngx (80.5 MB, 1 leg(s), 0s) [SSD: state-only]
|
||||
Tier 2 copied romm → /mnt/sys_drive/felhom-data/backups/secondary/romm (177.0 MB, 0 leg(s), 1s) [SSD: state-only]
|
||||
+25
@@ -0,0 +1,25 @@
|
||||
=== what does the rebuilt primary manifest DECLARE? ===
|
||||
db_dumps : []
|
||||
volume_dumps: None
|
||||
created_at : 2026-08-31T21:00:34Z
|
||||
controller : 0.231.0
|
||||
HOLLOW by R-403 predicate: True
|
||||
|
||||
=== the opengist log trail ===
|
||||
DiscoverDatabases: skipping container opengist (image=ghcr.io/thomiceli/opengist:1.13, not a database)
|
||||
ParseComposeHDDMounts: found 0 HDD mounts for /opt/docker/stacks/opengist/docker-compose.yml
|
||||
Recovery unit captured for opengist → /mnt/sys_drive/felhom-data/backups/primary/opengist (images=1, secrets-referenced=0, data_keys=0, portable-carried=0/0, withheld=0)
|
||||
RunHealthProbes: skipping opengist — last check 10s ago, effective interval 5m0s, healthy=true
|
||||
ParseComposeHDDMounts: found 0 HDD mounts for /opt/docker/stacks/opengist/docker-compose.yml
|
||||
ParseComposeHDDMounts: found 0 HDD mounts for /opt/docker/stacks/opengist/docker-compose.yml
|
||||
RunHealthProbes: skipping opengist — last check 20s ago, effective interval 5m0s, healthy=true
|
||||
Recovery unit captured for opengist → /mnt/sys_drive/felhom-data/backups/primary/opengist (images=1, secrets-referenced=0, data_keys=0, portable-carried=0/0, withheld=0)
|
||||
RunHealthProbes: skipping opengist — last check 30s ago, effective interval 5m0s, healthy=true
|
||||
RunHealthProbes: skipping opengist — last check 40s ago, effective interval 5m0s, healthy=true
|
||||
RunHealthProbes: skipping opengist — last check 50s ago, effective interval 5m0s, healthy=true
|
||||
backed up opengist (/mnt/sys_drive/felhom-data/backups/primary/opengist, 0 mandatory path(s))
|
||||
RunHealthProbes: skipping opengist — last check 1m0s ago, effective interval 5m0s, healthy=true
|
||||
RunHealthProbes: skipping opengist — last check 1m10s ago, effective interval 5m0s, healthy=true
|
||||
|
||||
=== is the APP healthy? ===
|
||||
opengist Up About a minute (healthy)
|
||||
+15
@@ -0,0 +1,15 @@
|
||||
=== does the OFF-SITE store now hold a hollow opengist snapshot? ===
|
||||
35ba9fe7 2026-08-31 21:01:08 demo-hp felhom-offbox,opengist /mnt/sys_drive/felhom-data/backups/primary/opengist
|
||||
----------------------------------------------------------------------------------------------------------------------
|
||||
1 snapshots
|
||||
|
||||
=== rotate the R-87 proof until it reaches opengist ===
|
||||
"reason":"" "stack":"bookstack" "verdict":"pass"
|
||||
"reason":"" "stack":"calibre-web" "verdict":"pass"
|
||||
"reason":"" "stack":"docmost" "verdict":"pass"
|
||||
"reason":"" "stack":"kimai" "verdict":"pass"
|
||||
"reason":"volumes_expected_none_captured" "stack":"opengist" "verdict":"fail"
|
||||
|
||||
=== the alarm, if any ===
|
||||
proof: opengist on snapshot 35ba9fe7 is READABLE AND EMPTY (volumes_expected_none_captured: opengist_data) — the store is not damaged; the backup does not contain this app's data
|
||||
PushEvent: type=offsite_proof_empty severity=error url=https://hub.felhom.eu/api/v1/event
|
||||
@@ -0,0 +1,38 @@
|
||||
# Phase 3 — R-357 against a real full disk. VERDICT: **PASS**
|
||||
|
||||
**Owed since 2026-08-25. Until tonight the destructive restore's free-space gate had only ever been
|
||||
proven by seam tests.** It has now met a genuinely full filesystem.
|
||||
|
||||
## Method
|
||||
|
||||
`calibre-web` lives on `hdd_1` — a **separate 1 TB NVMe device that does not back Docker**, chosen so
|
||||
filling it could not take the box down. `fallocate` reduced free space to **1 900 544 B** against a
|
||||
measured need of **5 878 421 B**.
|
||||
|
||||
## The non-effects, which are what matter
|
||||
|
||||
| assertion | result |
|
||||
|---|---|
|
||||
| refused **before** `StopStack` — the app never went down | **`Up 6 minutes (healthy)` before and after**, unchanged; 0 stop-related log lines |
|
||||
| no safety dump written | **0** files |
|
||||
| live data byte-identical | 22 files, tree fingerprint **`5a9b2db75dfd4ba4131adb3255670472`**, unchanged |
|
||||
| the message names the need and the free space, in Hungarian, not raw rsync | `Nincs eleg szabad hely a visszaallitashoz (5.6 MB szukseges, 1.8 MB szabad).` |
|
||||
| the log names both numbers and the non-effect | `REFUSING the destructive restore — need 5878421 B, free 1900544 B on /mnt/felhom-drives/hdd_1; the app was NOT stopped` |
|
||||
|
||||
## And it works when there IS space — the other half, without which the above proves nothing
|
||||
|
||||
Ballast removed → the **same** restore ran:
|
||||
`reconstituted calibre-web from snapshot ece64c87: 0 file(s) placed, 1 volume(s) replayed`, app back
|
||||
in 37 s, and the userdata tree fingerprint is **`5a9b2db75dfd4ba4131adb3255670472`** — identical to
|
||||
before the whole drill.
|
||||
|
||||
## The other three guards on the same full disk — none failed open
|
||||
|
||||
| job | behaviour | verdict |
|
||||
|---|---|---|
|
||||
| **Tier-2 run** | copied 3 apps successfully — its destination is on the *other* filesystem (`/var/lib/felhom`, 55 GB free), so a full `hdd_1` correctly did not stop it. Events `crossdrive_completed (info)` — mails nobody | correct |
|
||||
| **R-87 proof** | **`refused before any download`**: `Nincs eleg szabad hely (2.0 GB szukseges, 1.8 MB szabad)`. Reached **no verdict**, did **not** alarm, and said so: *"A visszaallitas nem futott le — a mentesrol semmi nem derult ki"* | correct — and this is the **shared `unitOnlyHeadroom` gate**, extracted today so the proof and the customer restore refuse at one floor with one sentence, now live-validated |
|
||||
| **integrity check** | **PASSED in 53.8 s** at 100 % depth — restic's cache lives on the container filesystem, not `hdd_1` | correct |
|
||||
|
||||
**No customer alarm fired from any of them.** The only events pushed were three `crossdrive_completed`
|
||||
at severity `info`, which `severityNotifies` drops.
|
||||
@@ -0,0 +1,10 @@
|
||||
=== filesystems, and which one backs Docker (the one NOT to fill) ===
|
||||
Filesystem Mounted on 1B-blocks Avail
|
||||
/dev/nvme0n1 /mnt/felhom-drives/hdd_1 1006980812800 949296590848
|
||||
/dev/mapper/pve-vm--9201--disk--1 /var/lib/felhom 73793978368 57945436160
|
||||
/dev/mapper/pve-vm--9201--disk--1 /var/lib/docker 73793978368 57945436160
|
||||
/dev/mapper/pve-vm--9201--disk--1 /mnt/sys_drive 73793978368 57945436160
|
||||
|
||||
=== fallocate available? (instant, metadata only, instantly reversible) ===
|
||||
/bin/fallocate
|
||||
yes
|
||||
@@ -0,0 +1,12 @@
|
||||
=== PHASE 3 setup: calibre-web lives on hdd_1 (a separate 1 TB device; Docker is NOT on it) ===
|
||||
--- live app state BEFORE ---
|
||||
container: calibre-web Up 5 minutes (healthy)
|
||||
userdata files: 22
|
||||
userdata bytes: 5952219 /mnt/felhom-drives/hdd_1/userdata
|
||||
userdata TREE fingerprint: 5a9b2db75dfd4ba4131adb3255670472
|
||||
|
||||
--- prepare a FULL off-site scratch for calibre-web and record its size ---
|
||||
scratch bytes (this is what the reconstitute must fit): 5808789 /mnt/felhom-drives/hdd_1/backups/offsite-restore/calibre-web
|
||||
marker: {"schema":1,"snapshot_id":"ece64c87","full":true,"finished_at":"2026-08-31T21:05:22Z"}
|
||||
--- free space now ---
|
||||
avail: 949296586752
|
||||
@@ -0,0 +1,24 @@
|
||||
=== FILL hdd_1: need=5808789 avail=949296586752 ballast=949294586752 (leaves ~2 MB, under the need) ===
|
||||
avail now: 1900544 (need 5808789) -> free < need: YES
|
||||
|
||||
=== app state immediately before the destructive restore ===
|
||||
calibre-web Up 6 minutes (healthy)
|
||||
|
||||
=== FIRE THE DESTRUCTIVE RECONSTITUTE ===
|
||||
|
||||
[http=302 wall=0.010286s]
|
||||
|
||||
=== ASSERT THE NON-EFFECTS ===
|
||||
--- 1. was the app ever stopped? ---
|
||||
calibre-web Up 6 minutes (healthy)
|
||||
stop-related log lines: 0
|
||||
--- 2. was a safety dump written? ---
|
||||
safety dump files created: 0
|
||||
--- 3. is the live userdata byte-identical? ---
|
||||
userdata files: 22
|
||||
userdata TREE fingerprint: 5a9b2db75dfd4ba4131adb3255670472
|
||||
--- 4. the refusal message and the log ---
|
||||
auth: valid session for POST /backup/offbox/reconstitute
|
||||
ServeHTTP: POST /backup/offbox/reconstitute from 172.18.0.4:56072
|
||||
calibre-web: REFUSING the destructive restore — need 5878421 B, free 1900544 B on /mnt/felhom-drives/hdd_1; the app was NOT stopped
|
||||
off-box reconstitute calibre-web (async): Nincs elég szabad hely a visszaállításhoz (5.6 MB szükséges, 1.8 MB szabad).
|
||||
+22
@@ -0,0 +1,22 @@
|
||||
=== THE DISK IS STILL FULL: 1900544 B free ===
|
||||
A full disk is exactly when a guard fails open. Fire all three.
|
||||
|
||||
--- A. TIER-2 RUN on a full disk ---
|
||||
"count":3 "message":"Cross-drive mentés elindítva 3 alkalmazásra" "ok":true
|
||||
Tier 2 copied calibre-web → /mnt/sys_drive/felhom-data/backups/secondary/calibre-web (5.6 MB, 1 leg(s), 0s) [SSD: state-only]
|
||||
Tier 2 copied paperless-ngx → /mnt/sys_drive/felhom-data/backups/secondary/paperless-ngx (80.5 MB, 1 leg(s), 0s) [SSD: state-only]
|
||||
Tier 2 copied romm → /mnt/sys_drive/felhom-data/backups/secondary/romm (177.0 MB, 0 leg(s), 0s) [SSD: state-only]
|
||||
|
||||
--- B. THE R-87 PROOF on a full disk (its scratch cannot fit) ---
|
||||
"skipped":false "stack":"paperless-ngx" "verdict":"" "message":"A visszaállítás nem futott le — a mentésről semmi nem derült ki"
|
||||
|
||||
--- C. THE INTEGRITY CHECK on a full disk (restic needs a cache) ---
|
||||
"duration_ms":53824 "ok":true "unreachable":false "message":"Az ellenőrzés rendben lezajlott" "ok":true
|
||||
|
||||
--- did ANY of them alarm the customer? ---
|
||||
Event pushed: crossdrive_completed (info) — Másodlagos mentés elkészült: calibre-web
|
||||
Event pushed: crossdrive_completed (info) — Másodlagos mentés elkészült: paperless-ngx
|
||||
Event pushed: crossdrive_completed (info) — Másodlagos mentés elkészült: romm
|
||||
(nothing above = no event pushed)
|
||||
auth: valid session for POST /api/debug/backup/offsite-proof
|
||||
proof: paperless-ngx refused before any download: Nincs elég szabad hely a visszaállításhoz (2.0 GB szükséges, 1.8 MB szabad).
|
||||
+17
@@ -0,0 +1,17 @@
|
||||
=== remove the ballast ===
|
||||
avail: 949296586752
|
||||
ballast files left: 0
|
||||
|
||||
=== step 5: the SAME destructive restore, now with space. It must WORK. ===
|
||||
before: calibre-web Up 9 minutes (healthy)
|
||||
--- log ---
|
||||
auth: valid session for POST /backup/offbox/reconstitute
|
||||
ServeHTTP: POST /backup/offbox/reconstitute from 172.18.0.4:56072
|
||||
reconstituted calibre-web from snapshot ece64c87: 0 file(s) placed, 1 volume(s) replayed, 0 DB dump(s) replayed, safety dump=., skewed=false
|
||||
off-box reconstitute calibre-web completed (async): files=0 dbs=0 snapshot=ece64c87
|
||||
--- app after ---
|
||||
after: calibre-web Up 37 seconds (healthy)
|
||||
--- userdata ---
|
||||
files: 22
|
||||
TREE fingerprint: 5a9b2db75dfd4ba4131adb3255670472
|
||||
(was 5a9b2db75dfd4ba4131adb3255670472 before the drill)
|
||||
@@ -0,0 +1,46 @@
|
||||
# Phase 4 — the proof's missing control and its edges. VERDICT: **PASS**
|
||||
|
||||
## The one that mattered — the false-alarm control now EXISTS and PASSES
|
||||
|
||||
Yesterday's report recorded that no app on `demo-hp` had **neither** a database **nor** a named
|
||||
volume, so R-87's "must not alarm on a legitimately empty app" case had **no live subject**. The whole
|
||||
design rests on that control.
|
||||
|
||||
**Found by reading all 53 catalogue composes, not by guessing:** exactly **one** template qualifies —
|
||||
**`bentopdf`** (single service `ghcr.io/alam00000/bentopdf:v2.8.6`, no database image, no top-level
|
||||
`volumes:` block, `needs_hdd: false`). *(My first scan reported 0 of 0 apps — the path was wrong; the
|
||||
positive control caught it.)*
|
||||
|
||||
Deployed, toggled into the off-site set, backed up (`454e6f8b`), and proved:
|
||||
|
||||
```
|
||||
proof: bentopdf PASSED on snapshot 454e6f8b in 2.224s — the backup holds what this app should have
|
||||
offsite_proof_empty events: 0 before, 0 after -> PASS: no alarm was raised
|
||||
```
|
||||
|
||||
Its unit is genuinely empty: `db_dumps: []`, `volume_dumps: None`, compose declares no volumes.
|
||||
**The guard does not fire on a healthy app that legitimately has nothing.**
|
||||
|
||||
## The other edges
|
||||
|
||||
| edge | expected | actual | verdict |
|
||||
|---|---|---|---|
|
||||
| 3. corrupt manifest → cannot judge | cannot judge | **could not be reached through the live path** — the off-site run's own capture phase **rewrote** my corrupted manifest before the push, so the snapshot was healthy and the `pass` was correct. Verified by restoring `5dcee6e3` and reading its manifest | **UNDETERMINED live**; covered by `TestR87_UnparseableManifestFails` (fail-closed, not cannot-judge — a documented divergence from the runbook's expectation, and R-403's rule) |
|
||||
| 4. no newest snapshot → not a failure | not a failure | **observed naturally**: while `bentopdf` was deployed but not yet toggled into the off-site set, the proof rotated all 8 apps and returned `no_snapshot:true`. It never picked bentopdf and never failed | **PASS** |
|
||||
| 5. two failures in an hour → one mail | one mail | **UNDETERMINED** — only two `offsite_proof_empty` were pushed tonight and they are **1 h 42 m apart** (19:21:45, 21:03:00), so they fall in different cooldown windows and do not exercise it. The controller-side half of the contract (no `stack_name`, so the hub keys coarsely) is pinned by `TestR87_NoPerAppCooldownEntryWasAdded` | **UNDETERMINED** |
|
||||
| 6. DB declared, no dump → fail, "intact but empty" | fail | **proven twice tonight** — Phase 2's natural `opengist` case, verbatim: *"READABLE AND EMPTY … the store is not damaged"* | **PASS** |
|
||||
|
||||
## A third instance of the same product behaviour, worth naming
|
||||
|
||||
Three separate attempts to get a damaged unit into the store through the front door were **repaired
|
||||
by the off-site run's own pre-push capture**: a stopped app's volume tar was re-made, a deleted unit
|
||||
was rebuilt, and a corrupted manifest was rewritten. **That is a reassuring property**, and it sharpens
|
||||
R-412: the capture repairs the *manifest and compose*, but it **cannot conjure a volume tar**, because
|
||||
the dump legs run on the backup schedule. That is the one gap through which R-412's hollow unit
|
||||
reached the store.
|
||||
|
||||
## And a confirmation of R-402's shape for the new fields
|
||||
|
||||
The hub's host page mentions `proof` **zero** times. The controller publishes `last_proof_*` and
|
||||
**no hub surface reads them** — exactly what the wire-contract allowlist entries added today say, and
|
||||
why they say "delete this entry when a hub surface reads it".
|
||||
@@ -0,0 +1,23 @@
|
||||
=== is bentopdf already known to the box? ===
|
||||
stacks on disk: 56
|
||||
bentopdf
|
||||
|
||||
=== deploy bentopdf (POST /stacks/bentopdf/deploy) ===
|
||||
[http=200 wall=0.073583s]
|
||||
=== containers named bentopdf ===
|
||||
(empty = none)
|
||||
=== the deploy log ===
|
||||
bentopdf/docker-compose.yml: hash match, skipped
|
||||
bentopdf/.felhom.yml: hash match, skipped
|
||||
ScanStacks: found stack "bentopdf" deployed=false composePath=/opt/docker/stacks/bentopdf/docker-compose.yml
|
||||
auth: valid session for POST /stacks/bentopdf/deploy
|
||||
ServeHTTP: POST /stacks/bentopdf/deploy from 172.18.0.4:49978
|
||||
deployHandler: stack=bentopdf method=POST
|
||||
=== the stack dir ===
|
||||
.felhom.yml
|
||||
docker-compose.yml
|
||||
=== deploy bentopdf ===
|
||||
{"ok":true,"message":"Telepítés elindítva – az állapot a kártyán követhető"}
|
||||
|
||||
[http=202]
|
||||
bentopdf Up 27 seconds (healthy)
|
||||
@@ -0,0 +1 @@
|
||||
{"ok":true,"data":{"app_config":null,"domain":"enkisfelhom.hu","logo_url":"/static/assets/bentopdf-logo.svg","metadata":{"display_name":"BentoPDF","description":"Adatvédelmi fókuszú PDF eszköztár","category":"tools","subdomain":"pdf","slug":"bentopdf","resources":{"mem_request":"100M","mem_limit":"384M","pi_compatible":true,"needs_hdd":false,"hungarian_ui":false},"deploy_fields":[{"env_var":"DOMAIN","label":"Domain","type":"domain","generate":"","default":"","required":true,"placeholder":"","description":"A szerver domain neve","locked_after_deploy":true},{"env_var":"SUBDOMAIN","label":"Aldomain","type":"subdomain","generate":"","default":"pdf","required":true,"placeholder":"","description":"Az alkalmazás aldomainje","locked_after_deploy":true}],"app_info":{"tagline":"Adatvédelmi fókuszú PDF eszköztár - a fájlok soha nem hagyják el a szervered","use_cases":["PDF összefűzés, szétválasztás és forgatás","PDF konvertálás képekké és képekből","Jelszóvédelem és titkosítás","Vízjel hozzáadása dokumentumokhoz","Minden feldolgozás a szerveren - a fájlok nem kerülnek külső szolgáltatóhoz"],"first_steps":["Nyisd meg a pdf.DOMAIN címet a böngészőb
|
||||
@@ -0,0 +1,22 @@
|
||||
=== back bentopdf up so the proof has a snapshot ===
|
||||
|
||||
=== its unit: does it legitimately carry NOTHING? ===
|
||||
1673 compose/.felhom.yml
|
||||
286 compose/app.yaml
|
||||
1109 compose/docker-compose.yml
|
||||
1087 manifest.json
|
||||
db_dumps : []
|
||||
volume_dumps: None
|
||||
compose top-level volumes:
|
||||
(nothing above = none declared)
|
||||
|
||||
=== wait for the run to finish, then rotate the proof to bentopdf ===
|
||||
"reason":"" "stack":"bookstack" "verdict":"pass"
|
||||
"reason":"" "stack":"calibre-web" "verdict":"pass"
|
||||
"reason":"" "stack":"docmost" "verdict":"pass"
|
||||
"reason":"" "stack":"kimai" "verdict":"pass"
|
||||
"reason":"" "stack":"opengist" "verdict":"pass"
|
||||
"reason":"" "stack":"paperless-ngx" "verdict":"pass"
|
||||
"reason":"" "stack":"privatebin" "verdict":"pass"
|
||||
"reason":"" "stack":"romm" "verdict":"pass"
|
||||
"no_snapshot":true "reason":"" "stack":"" "verdict":""
|
||||
@@ -0,0 +1,17 @@
|
||||
=== is bentopdf toggled INTO the off-site set? ===
|
||||
keys: ['offbox_enlarge_notice_seeded', 'offbox']
|
||||
|
||||
=== does bentopdf have an off-site snapshot? ===
|
||||
|
||||
=== and did opengist self-heal? ===
|
||||
1750 compose/.felhom.yml
|
||||
287 compose/app.yaml
|
||||
1260 compose/docker-compose.yml
|
||||
1119 manifest.json
|
||||
181248 volume-dumps/opengist_opengist_data.tar
|
||||
=== toggle bentopdf into the off-site set ===
|
||||
[http=302 wall=0.010921s]
|
||||
bentopdf backed up after ~130s
|
||||
454e6f8b 2026-08-31 21:25:37 demo-hp felhom-offbox,bentopdf /mnt/sys_drive/felhom-data/backups/primary/bentopdf
|
||||
----------------------------------------------------------------------------------------------------------------------
|
||||
1 snapshots
|
||||
+14
@@ -0,0 +1,14 @@
|
||||
=== event baseline before ===
|
||||
offsite_proof_empty events in the last 10m: 0
|
||||
|
||||
=== rotate the proof to bentopdf - THE FALSE-ALARM CONTROL ===
|
||||
"reason":"" "skipped":true "stack":"" "verdict":""
|
||||
"reason":"" "skipped":true "stack":"" "verdict":""
|
||||
"reason":"" "skipped":true "stack":"" "verdict":""
|
||||
"reason":"" "stack":"bentopdf" "verdict":"pass"
|
||||
|
||||
=== THE ACCEPTANCE: bentopdf must PASS and must NOT alarm ===
|
||||
offsite_proof_empty events now: 0 (was 0)
|
||||
PASS: no alarm was raised
|
||||
|
||||
proof: bentopdf PASSED on snapshot 454e6f8b in 2.224s — the backup holds what this app should have
|
||||
@@ -0,0 +1,15 @@
|
||||
=== EDGE 3: a CORRUPT MANIFEST reaches the store, then the proof judges it ===
|
||||
primary manifest now: {this is not json
|
||||
--- back it up so the CORRUPT manifest is what the proof restores ---
|
||||
pushed after ~10s
|
||||
--- rotate the proof to bentopdf ---
|
||||
"reason":"" "stack":"bentopdf" "verdict":"pass"
|
||||
|
||||
RUNBOOK EXPECTED: cannot judge. IMPLEMENTED: fail-closed (R-403's rule: a unit whose
|
||||
manifest cannot be read cannot be vouched for). Reporting what actually happened.
|
||||
proof: bentopdf PASSED on snapshot 5dcee6e3 in 2.194s — the backup holds what this app should have
|
||||
|
||||
=== restore the manifest ===
|
||||
restored: {
|
||||
"schema_version": 2,
|
||||
"app_name": "
|
||||
+12
@@ -0,0 +1,12 @@
|
||||
=== files in snapshot 5dcee6e3 ===
|
||||
/mnt/sys_drive/felhom-data/backups/primary/bentopdf/manifest.json
|
||||
/mnt/sys_drive/felhom-data/backups/primary/bentopdf/compose/app.yaml
|
||||
/mnt/sys_drive/felhom-data/backups/primary/bentopdf/compose/.felhom.yml
|
||||
/mnt/sys_drive/felhom-data/backups/primary/bentopdf/compose/docker-compose.yml
|
||||
=== its manifest, first 70 bytes ===
|
||||
{
|
||||
"schema_version": 2,
|
||||
"app_name": "bentopdf",
|
||||
"display_name": "
|
||||
=== is it the corruption I planted, or a rewritten one? ===
|
||||
the manifest is VALID - the capture rewrote it before the push
|
||||
@@ -0,0 +1,7 @@
|
||||
=== offsite_proof_empty events the CONTROLLER pushed tonight ===
|
||||
2026/08/31 19:21:45 notifier.go:234: [INFO] Event pushed: offsite_proof_empty (error) — A(z) opengist legutÃ
|
||||
2026/08/31 21:03:00 notifier.go:234: [INFO] Event pushed: offsite_proof_empty (error) — A(z) opengist legutÃ
|
||||
|
||||
=== what the HUB recorded and whether it MAILED ===
|
||||
http=404
|
||||
offsite_proof_empty rows found at the hub: 0
|
||||
@@ -594,6 +594,9 @@ class (an image `VOLUME` at an unmounted path) is still live — `immich-server`
|
||||
| **R-408** | **`RestoreOffboxScratch` takes NO single-writer flag, and the file that depends on that invariant states it as universal.** `offbox_integrity.go:28` reads *"Every off-site operation takes `acquireRunning` for exactly that reason"* — the reason being that `resticStep` escalates to `unlock --remove-all` and is safe only because the in-process mutex proves no sibling operation is live. **Measured 2026-08-31:** `grep -rn 'acquireRunning()'` finds nine non-test callers and `RestoreOffboxScratch` (`offbox_restore.go:234`) is not among them. `restore_wizard.go:174` records the same fact independently — *"`RestoreOffboxScratch` never acquires it at all"* — and the UI works around it with a separate display flag (`opRunning`), so the gap is known at the web layer and unknown at the one that reasons about repository safety. **The exposure today is small and the exposure tomorrow is not:** the web handler's `restoreOpBlocked()` fences the only caller that exists, and restic's restore takes no lock (R-407's sampler), so nothing currently collides. **An unattended restore-test — R-87 — would be the first caller with no web handler in front of it.** | **OPEN — MEDIUM** | R-87, R-359 | Decide ONE way: either `RestoreOffboxScratch` takes `acquireRunning` (and every existing caller is re-checked for the double-acquire refusal `tier2_restore.go:183` warns about), or `offbox_integrity.go:28`'s sentence is corrected to name the exception. Whichever is chosen, **pin it with a test** — this is a comment asserting an invariant with nothing holding it. Do this BEFORE R-87 ships anything. | CC |
|
||||
| **R-409** | **Nothing in the product can vouch for the bytes of a restored recovery unit — the only hash record covers 0.002 % of it.** MEASURED on demo-hp 2026-08-31 against kimai's restored unit: `manifest.json`'s `checksums` object carries sha256 for `.felhom.yml` (2 235 B), `app.yaml` (488 B) and `docker-compose.yml` (2 195 B) — **4 918 bytes of a 213 231 242-byte unit**. The database dump (48 217 B) and the two named-volume tars (160 331 776 B + 52 845 056 B) — the recoverable data, 99.998 % of the bytes — have no recorded hash anywhere. **And nothing else supplies one:** restic 0.14.0's `restore --verify` is a size-and-mtime reconciliation (a size-and-mtime-preserving one-byte corruption of a 160 MB tar passed clean, red-proofed), and `restic ls --json` file nodes in 0.14.0 carry name, size, mode, uid/gid and three timestamps and **no content hash**. **So "the restore produced correct files" is currently unanswerable by any automated means.** **What is NOT claimed here:** `restic check --read-data-subset=100%` already proves the STORE's packs, and the config files that ARE hashed are the ones a wrong-content failure would be hardest to spot in. | **OPEN — MEDIUM** | R-87, R-361 | Cheapest fix, and it is already half-built: extend the capture's `checksums` to cover `db_dumps` and `volume_dumps` — R-361 already computes a canonical dump sha256 to prove itself, so the value exists at capture time. Then a restore-test has a real reference and R-87's narrow version becomes a content check rather than a completeness one. Evidence: `audits/SPIKE-restic-restore-test-2026-08-31.md` §Q2, §Q3. | CC |
|
||||
| **R-410** | **`golden_currency_gate.py` is satisfied by a DIRECTORY NAME — `mkdir documentation/tests/golden-<VER>-<DATE>` turns it green with no bake behind it.** `EVIDENCE_RE = ^golden-(\d+)\.(\d+)\.(\d+)-\d{4}-\d{2}-\d{2}$` matched against `os.listdir` (`scripts/golden_currency_gate.py:89,123`) — it never opens the directory, never looks for a log, never checks a sha, and never asks Gitea whether the package exists. Noticed 2026-08-31 while the 0.230.0 bake turned it from red to green: **I created the directory before the bake finished, and the gate would have passed at that moment.** **What the gate DOES say honestly:** its own success line already reads *"this checks the BAKE, not the vouch"* — so the vouch hole is declared. **This one is not:** nothing tells a reader the bake check is a filename check. **Class:** an instrument that cannot distinguish the thing from a label for the thing — the same shape as R-378's whole-field match and R-233's un-matchable grep, aimed this time at the release gate. **Exposure today is low** because the runbook produces a real evidence directory and two bakes in a row have; it is the NEXT hurried session that pays. | **OPEN — LOW** | R-242 | Make it read something the bake alone can produce: the `GOLDEN_SHA256=` line in the directory's `bake.log`, or a HEAD against the Gitea package URL for that version. Prefer the log — it keeps the gate offline and `--fast`. Ship a red-proof: an empty `golden-9.9.9-2026-01-01/` directory must FAIL. | CC |
|
||||
| **R-411** | **A background job DELETES the lock of a live customer restore, and logs it as a crash that did not happen.** MEASURED on demo-hp 2026-08-31 during the overnight soak, through the product's own endpoints — this is R-408's consequence, which until tonight had only been reasoned about. **The chain, every step observed:** (1) a customer full-restore runs `OffboxRestorePrepareFull` → `restic stats`, and **`restic stats` TAKES A REPOSITORY LOCK** (clean-room test: nothing else running, 4x stats, sampler reads `locks=1`); (2) the restore holds `opRunning` but **NOT `acquireRunning`** (R-408), so the integrity check is not blocked and runs concurrently; (3) the check meets that lock, and `resticStep` escalates to **`unlock --remove-all`** — caught by the argv sampler at **20:50:51 with `restore 3c11059b --target …` and `unlock --remove-all` in the SAME sample**; (4) the log says *"cleared a stale exclusive lock left by a previous crash (single-writer repo)"* — **there was no crash**, and `resticStep` cannot know there was, because it fires on ANY `repository is already locked`. **THE CUSTOMER-FACING CONSEQUENCE WAS CONTAINED, and that is R-359's guard working:** the check returned `ok:false` in 6.7 s and was classified **Unreachable, NOT damage** — *"the check could not run to a verdict (other) — NOT reported as damage"* — so no `backup_integrity_failed` and no customer mail. Due-ness was not advanced either, so it retries. **What is NOT contained:** a live operation's lock is deleted by a background job; the single-writer premise `resticStep`'s own comment rests on is false in this pairing; and that night's integrity check silently did not verify the store, with only a WARN. **The opposite direction is FENCED and was measured too:** five restores fired into a running check at 5/15/25/35/40 s offsets were ALL refused by `restoreOpBlocked` (`offbox_handlers.go:358`), zero restic invoked — so the hazard is reachable only restore-FIRST. | **OPEN — MEDIUM** | R-408, R-407, R-359 | Decide ONE way, and R-408 is the same decision: either `RestoreOffboxScratch` (and the full-restore preparation) takes `acquireRunning`, or `resticStep`'s escalation stops claiming a crash it cannot verify and refuses instead of removing. **Pin whichever is chosen with a test that reproduces this pairing** — a unit test on `resticStep` alone cannot see it. Evidence: `audits/DRILL-soak-2026-08-31/phase1-lock-collision/`. | CC |
|
||||
| **R-412** | **A lost recovery unit is rebuilt WITHOUT its volume dumps, and the off-site backup then ships that hollow unit and reports success.** OBSERVED on demo-hp 2026-08-31 during the soak, produced by the product with no construction — **this is the natural instance of R-403's shape that yesterday's R-87 session could not produce and had to hand-build.** **The chain, every step in the log:** (1) `opengist`'s primary unit was removed (a restore, a crash mid-capture or a remount does the same — R-403's own named causes); (2) the 5-minute capture rebuilt it — *"Recovery unit captured for opengist"* — with compose and manifest but **no volume tar**, manifest reading `db_dumps: []`, `volume_dumps: None` (the key absent entirely), **185 664 B → 4 382 B**; (3) the off-site backup pushed it and logged *"backed up opengist … 0 mandatory path(s)"* — a SUCCESS line over a backup containing none of the app's data; (4) the newest off-site snapshot `35ba9fe7` is now hollow. **THE CAPTURE IS NOT WRONG IN ISOLATION** — a capture describing an empty tree as empty is correct, and R-403 deliberately refused to guard it for that reason. **What is wrong is that nothing between the capture and the off-site push notices that a unit which HAD dumps yesterday has none today**, and the run reports success. The volume-dump leg runs on the backup schedule, not on capture, so the window is a whole cycle wide. | **OPEN — HIGH** | R-403, R-87, R-413 | Decide where the notice belongs: the capture (which R-403 fenced off), the off-site run's own pre-push phase (which already re-captures and could compare against what it is about to replace), or a shrink-detector on the primary. **Do NOT simply guard the capture** — 08 §8.2 records why that would make the manifest lie. Evidence: `audits/DRILL-soak-2026-08-31/phase2-guard-interactions/`. | CC |
|
||||
| **R-413** | **R-87's proof caught a naturally-produced hollow snapshot, end to end, unattended — the validation yesterday's session could only do with a declared hand-built fixture.** 2026-08-31 soak, demo-hp. After R-412's chain left `opengist`'s newest off-site snapshot hollow, the nightly proof rotated to it and returned **`verdict:"fail"`, `reason:"volumes_expected_none_captured"`, missing `opengist_data`**, logged *"READABLE AND EMPTY — the store is not damaged; the backup does not contain this app's data"*, and pushed **one** `offsite_proof_empty` at severity `error`. The four apps ahead of it in the rotation all passed, so the discrimination is real and not a constant fail. **This is recorded as a row rather than only as a report line because it upgrades a claim:** the capability map's R-87 row cites a CONSTRUCTED failing case; it can now cite a natural one. | **CLOSED 2026-08-31 — the claim it upgrades is recorded** | R-87, R-412 | Nothing to build. When the capability map is next touched, cite this instead of the constructed case. | CC |
|
||||
|
||||
<!-- DUE-CHECKS-BEGIN — machine-readable. Parsed by scripts/due_checks_gate.py.
|
||||
One row per dated check. The R-number must have a row above. Dates are UTC.
|
||||
|
||||
Reference in New Issue
Block a user