diff --git a/documentation/audits/CAMPAIGN-11-recovery-journey-2026-08-05.md b/documentation/audits/CAMPAIGN-11-recovery-journey-2026-08-05.md index 4b804a4..3b74e81 100644 --- a/documentation/audits/CAMPAIGN-11-recovery-journey-2026-08-05.md +++ b/documentation/audits/CAMPAIGN-11-recovery-journey-2026-08-05.md @@ -434,6 +434,67 @@ because two of them nearly produced false findings. --- +## 8b. Phase 4 — the unattended soak + +**23:56 → 04:35, venue untouched.** 30 five-minute samples plus a full log census. **Expectations were +pre-registered in the journal BEFORE the window**, in both directions, so nothing here is fitted +afterwards. + +### Everything scheduled fired, exactly once, on time + +| job | due | result | +|---|---|---| +| `db-dump` | 02:30 | ✅ 5.237 s | +| `tier2-backup` | 03:30 | ✅ 118 ms — **and the copy is real** (below) | +| `fill-watch` | 03:30 | ✅ | +| `metrics-prune` | 04:00 | ✅ | +| **`offbox-backup`** | **04:15** | ✅ **24.884 s — `snapshot_count` 1 → 2, `last_status: ok`** | + +**The off-site tier runs itself, unprompted, on a box that was rebuilt twice and had its repository set +aside four hours earlier.** That is the strongest positive of the whole campaign for the backup +promise, as distinct from the recovery journey. + +### Nothing fired that should not have + +`needs_credential` 0 · `offsiteheal` 0 · `offbox_repo_orphaned` 0 in-window · `offsite_repo_key_changed` +0 · `escrow blob SERVED` 0 · `host_stale`/`host_recovered` 0 · self-update 0 · operator emails 0. + +> **§4.2's negative control passes.** A box that HAS a target did not declare `needs_credential` once +> in five hours. R-218's fix is not over-firing in the other direction — which does **not** substitute +> for its positive half, still owed. + +### Investigated and DISPROVED — `tier2-backup` in 118 ms + +It looked like a scheduled backup that silently no-ops. It is not: `Tier 2 copied calibre-web → +/mnt/felhom-drives/mentes/backups/secondary/calibre-web (818.5 KB, 1 leg(s), 0s)`, and the copy is on +the backup drive. 388 KB on local NVMe in 118 ms is honest. **No finding.** + +### A correction to my own pre-registration + +I pre-registered a `backup_run_digest` event. **No such event type exists** — that is a *test +filename*, and the real one is **`backup_run_failures`**, a failures digest whose silence on a clean +night is correct. Reporting it as a miss would have been a finding invented by a bad reading. + +**What survives the correction:** the off-site run emitted **no hub event at all**, while both lesser +tiers announced success (`db_dump_completed`, `crossdrive_completed`). Failures are covered by +`backup_run_failures` and staleness by the hub's tier deadline monitor +(`offsiteBackupStaleAfter = 8 days`), so this is **a consistency wrinkle, not a blind spot** — +recorded, not filed. + +### What should have fired and did not — answered in both directions + +- **The restore-test did not run, and that is CORRECT** — `eval_interval=6h` (armed 23:29:43, first + evaluation ~05:29) with a **24 h settle** on archives hours old. **Pre-registered as "expected not to + run"**; without that, its silence would have read as a gap. +- **The agent's whole-guest tier did not run, and whether it should have is NOT RESOLVABLE.** The box + reports `0 backups` all night; the agent is emphatically alive (**2 091 of its own lines** since + 00:00, polling the guest at 04:17:57); **but routine local-api requests are not logged at INFO** — a + five-hour search for `local-api` returns **0** on a box that demonstrably served such calls earlier — + so "no `/backup/due` poll" is **not evidence**. The hub's deadline monitor is equally invisible at + INFO. **Recorded as an open question, not scored as a pass.** + +--- + ## 9. Invariants at every phase boundary | | | verdict | diff --git a/documentation/tests/campaign11-evidence-2026-08-05/journal-phase24.md b/documentation/tests/campaign11-evidence-2026-08-05/journal-phase24.md index c5ca5b2..4fa1235 100644 --- a/documentation/tests/campaign11-evidence-2026-08-05/journal-phase24.md +++ b/documentation/tests/campaign11-evidence-2026-08-05/journal-phase24.md @@ -705,3 +705,131 @@ backup: restore-test scheduler starting (per-archive due-check) eval_interval=6 - Whether the agent's local tier fires tonight depends on when its 24 h cadence last elapsed on a box built today. + +## Phase 4 — results, against the pre-registration + +**Window observed: 2026-08-05 23:56 → 2026-08-06 04:35 CEST.** The venue was not touched: no endpoint +driven, no service restarted, nothing configured. **30 five-minute samples** of the box's own +`settings.json` and the hub's host row, plus a full log census at the end. + +### What fired — and every daily job fired exactly once, on time + +Census taken with **no `tail`** (the documented "tail silently drops rows" trap — the first checkpoint +hit it and was re-run): + +| job | scheduled | ran | completed | evidence | +|---|---|---|---|---| +| `db-dump` | 02:30 | **1** | **1** | `00:30:00Z Running` → `00:30:05Z completed (took 5.237s)` | +| `tier2-backup` | 03:30 | **1** | **1** | `01:30:00Z` → `completed (118ms)` | +| `fill-watch` | 03:30 | **1** | **1** | `01:30:00Z` → `completed (0s)` | +| `metrics-prune` | 04:00 | **1** | **1** | — | +| **`offbox-backup`** | **04:15** | **1** | **1** | `02:15:00Z Running` → `02:15:24Z completed (took 24.884s)` | + +**The one this campaign cares about, verbatim:** + +``` +02:15:00 [scheduler] Running job: offbox-backup +02:15:00 [offbox] backup run started (1 app(s) toggled) +02:15:05 [offbox] pre-push dump leg completed in 5.203s — snapshot pair is coherent +02:15:14 [offbox] backed up calibre-web (…/backups/primary/calibre-web, 1 mandatory path(s)) +02:15:24 [offbox] backup OK: 1 app(s) backed up, 2 snapshot(s), 18s +``` + +**Pre-registered prediction met exactly:** `snapshot_count` **1 → 2**, `last_status: ok`, +`repo_size_bytes` 27 019 → **51 206**, `last_success 2026-08-06T02:15:24Z`. **The off-site tier runs +itself, unprompted, on a box that was rebuilt twice and had its repository set aside hours earlier.** + +Two events reached the hub, and both are the tier announcing success: + +``` +02:30:05 Event from c11: db_dump_completed (info) — Adatbázis mentés elkészült +03:30:00 Event from c11: crossdrive_completed (info) — Másodlagos mentés elkészült: calibre-web +``` + +### Investigated and DISPROVED — `tier2-backup` completing in 118 ms + +118 ms looked like a scheduled backup that silently no-ops. **It is not.** The copy is real and on the +disk: + +``` +[backup] Tier 2 copied calibre-web → /mnt/felhom-drives/mentes/backups/secondary/calibre-web + (818.5 KB, 1 leg(s), 0s) +[backup] Tier 2 run complete: 1 app(s) processed (incl. volume-only — F6) + +/mnt/felhom-drives/mentes/backups/secondary/calibre-web ← present on the BACKUP drive +``` + +388 KB of source on local NVMe in 118 ms is honest. **No finding.** + +### What must NOT have fired — and none of it did + +Counted over the whole window, box side and hub side: + +| | box | hub | +|---|---|---| +| `needs_credential` | **0** | — | +| `offsiteheal` / `offsite_selfheal_restaged` | **0** | **0** | +| `offbox_repo_orphaned` | **0** in-window | **0** | +| `offsite_repo_key_changed` | — | **0** | +| `escrow blob SERVED` | — | **0** | +| `host_stale` / `host_recovered` | — | **0** | +| any controller self-update | **0** | — | +| `Operator email sent` for c11 | — | **0** | + +> **§4.2's negative control PASSES.** A box that HAS an off-site target did **not** declare +> `needs_credential` even once in five hours, and the hub's self-heal never fired. R-218's fix is not +> over-firing in the other direction. This does not substitute for its positive half, which is still +> owed. + +The three `orphan` hits in the box's log were placed in time rather than counted blind: all three are +**Phase 2's own set-aside at 21:30–21:32Z**, before the window opened. **Zero after.** + +### A correction to my own pre-registration — item 4 was wrong + +I pre-registered *"a `backup_run_digest` event reaches the hub after a backup run"*. **There is no such +event type.** `backup_run_digest` is a **test filename** (`internal/notify/backup_run_digest_test.go`), +which is where I took it from — a census of the hub's `allowedEventTypes` shows the real one is +**`backup_run_failures`**, a *failures* digest. **Its silence on a clean night is correct**, and +reporting it as a miss would have been a finding invented by my own bad reading. + +**One real observation survives that correction.** The off-site run emitted **no hub event at all**, +while both lesser tiers announced themselves (`db_dump_completed`, `crossdrive_completed`). So the +operator's event stream carries a nightly "DB dump done" and "second copy done" and **nothing** when +the tier the whole campaign is about succeeds. **Mitigations exist and are named rather than assumed:** +failures are covered by `backup_run_failures`, and off-site staleness by the hub's own tier deadline +monitor (`deadline_tiers.go`, `offsiteBackupStaleAfter = 8 days`). **A consistency wrinkle, not a blind +spot** — recorded, not filed. + +### The two genuinely uncertain items, resolved honestly + +- **The restore-test did NOT run — and that is correct, as pre-registered.** `eval_interval=6h` with + the scheduler armed 23:29:43, so the first evaluation is ~05:29; and `settle=24h` on archives hours + old. **Predicted not to run, did not run.** Had this not been pre-registered it would have read as a + gap. +- **The agent's whole-guest tier did NOT run, and whether it should have is NOT RESOLVABLE with the + instruments available.** Stated as an open question rather than scored either way: + - Measured: the box reports **`0 backups`** in every host-report all night (03:59:47, 04:14:47), and + no whole-guest backup, vzdump, snapshot or quiesce line appears in the agent journal. + - **The agent is emphatically alive** — 67 251 journal lines since 00:00, **2 091 of them from + `felhom-agent` itself**, and it was polling the guest at 04:17:57. + - **But the instruments cannot answer the question.** Routine local-api requests are not logged at + INFO: a search for `local-api` over five hours returns **0** on a box that demonstrably served + `local-api: recovering the offsite repository password` earlier in the session. So "0 `/backup/due` + polls" is **not evidence that no poll happened**. The hub's deadline monitor is equally invisible — + a census for `deadline|backup_missing|tier` across all customers returns **0** at INFO. + - **What can be said:** no alarm fired for c11 all night other than F11's own, and the tier is armed + with a 24 h cadence on a box whose local tier has never run. **Whether a first-ever whole-guest + backup was due and skipped, or correctly not yet due, needs an instrument that does not exist + today.** → recorded as an open question, not as a finding. + +### Phase 4 verdict + +**The machine ran a full scheduled cycle correctly and unaided.** Five of five daily jobs fired on +time and completed; the off-site tier produced a second snapshot by itself; the two local tiers +reported success to the operator; and **nothing fired that should not have** — including the +self-heal, which is R-218's negative control. + +**The one thing a soak like this cannot do is prove the absence of an alarm was right**, and where that +was true it is said so: the restore-test's silence was predicted in advance, and the whole-guest +tier's silence is left explicitly unresolved rather than counted as a pass. +