From 3ca9b71c73916202d105e5a5bac7d1ad99a299bb Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Mon, 26 Oct 2026 19:17:19 +0100 Subject: [PATCH] R-435 read and closed: the 2026-10-26 windows (hub records + mailbox; box logs lost to restarts, said plainly) --- STATUS.md | 2 +- .../r435-window-read-2026-10-26/README.md | 20 +++++++++++++++++ .../hub-windows-and-alarms.txt | 22 +++++++++++++++++++ .../report-count-replay.txt | 9 ++++++++ documentation/backlog/CLOSED-ITEMS.md | 6 +++++ documentation/backlog/OPEN-ITEMS.md | 2 -- 6 files changed, 58 insertions(+), 3 deletions(-) create mode 100644 documentation/audits/r435-window-read-2026-10-26/README.md create mode 100644 documentation/audits/r435-window-read-2026-10-26/hub-windows-and-alarms.txt create mode 100644 documentation/audits/r435-window-read-2026-10-26/report-count-replay.txt diff --git a/STATUS.md b/STATUS.md index 373652d3..5976f178 100644 --- a/STATUS.md +++ b/STATUS.md @@ -24,7 +24,7 @@ ## What we work on - Built, not released: a BYO box removes our SSH file in the same update (R-1285; the agent waits for a live BYO proof); held apps reach you (R-1291, controller + hub, proven on a test hub). -- Dated checks, run by CC. 2026-10-27: the qBittorrent line test on a seeding box, with DooPlex's qBittorrent as the peer (R-1250, your yes); the weekly clean-up window (R-435; the logs of the last one were lost to restarts). 2026-10-30: D35, website and installer to Cloudflare, starts (R-1228, ruled yes). +- Dated checks, run by CC. 2026-10-27: the qBittorrent line test on a seeding box, with DooPlex's qBittorrent as the peer (R-1250, your yes). Done 2026-10-26: the weekly clean-up windows removed only old copies and raised no false alarm (read from the hub's records and your mailbox). 2026-10-30: D35, website and installer to Cloudflare, starts (R-1228, ruled yes). ## Waiting on you — decide diff --git a/documentation/audits/r435-window-read-2026-10-26/README.md b/documentation/audits/r435-window-read-2026-10-26/README.md new file mode 100644 index 00000000..d8f9ff0f --- /dev/null +++ b/documentation/audits/r435-window-read-2026-10-26/README.md @@ -0,0 +1,20 @@ +# R-435 — the weekly clean-up windows of 2026-10-26, read (2026-10-26 evening; the brief dated it 2026-10-27) + +**The box logs are gone, said plainly.** The windows ran 2026-10-26 03:15–03:18 UTC. Every test box's controller +restarted twice that day (the 09:07 and 13:27 UTC floors), and the hub pod at 13:08 (hub 0.172.0), so neither the box's +window lines nor the hub's DEBUG „explained by clean-up windows" line exist any more. The check is **reproduced from two +other channels**: the hub's own records (the database copied with its `-wal` from the running pod) and the mailbox. + +| Box | Window | Copies before → after | Box result | Reports the hub stored | Drop alarm | +|---|---|---|---|---|---| +| Tester 1 | 15: 03:15:52 → closed 03:16:06 | 78 → 57 (21 removed, cap 39) | pruned | 74 (01:31:56) → 57 (03:16:56) | none | +| demo-felhom | 14: 03:15:48 → closed 03:16:00 | 63 → 48 (15 removed, cap 31) | pruned | 58 (01:31:53) → 48 (03:16:53) | none | +| demo-hp | 16: 03:17:52 | 359 → 359 | guard-refused (R-1294) | 345 → 359 (no fall) | — | + +- **The positive control:** the hub DID receive the lower count, 50 s after each window closed — so its checker had a + fall to judge, and each fall (17, 10) is within what its window removed (21, 15). Without the window credit the D7 + rule mails an error for even one missing copy. +- **No drop alarm:** no `offsite_snapshots_*` / `offsite_window_drop` event or mail row for either box + (`hub-windows-and-alarms.txt`), and no such mail in the operator mailbox for 2026-10-26; the same mailbox search does + find that night's demo-hp refusal mail (03:17:56Z), so the search sees off-site mails. +- Files: `hub-windows-and-alarms.txt`, `report-count-replay.txt`. The database copy was deleted after the read. diff --git a/documentation/audits/r435-window-read-2026-10-26/hub-windows-and-alarms.txt b/documentation/audits/r435-window-read-2026-10-26/hub-windows-and-alarms.txt new file mode 100644 index 00000000..d307ac69 --- /dev/null +++ b/documentation/audits/r435-window-read-2026-10-26/hub-windows-and-alarms.txt @@ -0,0 +1,22 @@ +# offsite_windows since 2026-10-18 (hub DB copied WITH its -wal from the running pod, 2026-10-26 18:15Z) +# id, customer, opened, closes_by, closed, count_before, count_after, box_result, close_reason, max_remove +(10, 'demo-felhom', '2026-10-19 02:15:41', '2026-10-19 02:35:41', '2026-10-19 02:15:51', 35, 28, 'pruned', 'box', 17) +(11, 'tester-1', '2026-10-19 02:15:53', '2026-10-19 02:35:53', '2026-10-19 02:16:12', 68, 50, 'pruned', 'box', 34) +(12, 'demo-hp', '2026-10-19 02:17:53', '2026-10-19 02:37:53', '2026-10-19 02:18:24', 324, 261, 'pruned', 'box', 162) +(13, 'Tester4', '2026-10-20 17:07:48', '2026-10-20 17:27:48', '2026-10-20 17:07:51', 17, 17, 'nothing', 'box', 8) +(14, 'demo-felhom', '2026-10-26 03:15:48', '2026-10-26 03:35:48', '2026-10-26 03:16:00', 63, 48, 'pruned', 'box', 31) +(15, 'tester-1', '2026-10-26 03:15:52', '2026-10-26 03:35:52', '2026-10-26 03:16:06', 78, 57, 'pruned', 'box', 39) +(16, 'demo-hp', '2026-10-26 03:17:52', '2026-10-26 03:37:52', '2026-10-26 03:17:55', 359, 359, 'guard-refused', 'box', 179) + +# events + notification_log 2026-10-25 22:00 -> copy time: every offsite_* / *drop* type +event ('2026-10-26 03:17:55', 'demo-hp', 'offsite_prune_guard_refused', 'error') +event ('2026-10-26 09:30:53', 'Tester4', 'offsite_reissued', 'info') +event ('2026-10-26 09:32:56', 'Tester4', 'offsite_key_installed', 'info') +event ('2026-10-26 10:33:41', 'Tester4', 'offsite_delivery_stuck', 'warning') +event ('2026-10-26 11:51:57', 'Tester4', 'offsite_reissued', 'info') +event ('2026-10-26 11:54:05', 'Tester4', 'offsite_key_installed', 'info') +mail ('2026-10-26 03:17:56', 'demo-hp', 'offsite_prune_guard_refused', 'sent', 'operator') +mail ('2026-10-26 03:17:56', 'demo-hp', 'offsite_prune_guard_refused', 'skipped', 'customer') +mail ('2026-10-26 10:33:41', 'Tester4', 'offsite_delivery_stuck', 'sent', 'operator') +mail ('2026-10-26 10:33:41', 'Tester4', 'offsite_delivery_stuck', 'skipped', 'customer') +mail ('2026-10-26 10:33:41', 'Tester4', 'offsite_credential_restaged', 'refused', 'operator') diff --git a/documentation/audits/r435-window-read-2026-10-26/report-count-replay.txt b/documentation/audits/r435-window-read-2026-10-26/report-count-replay.txt new file mode 100644 index 00000000..5ae37525 --- /dev/null +++ b/documentation/audits/r435-window-read-2026-10-26/report-count-replay.txt @@ -0,0 +1,9 @@ +== tester-1 (reports 2026-10-26 01:30–05:00 UTC; a line only where the count changes) + 2026-10-26 01:31:56 snapshot_count 74 | last_success 2026-10-25T03:16:00Z + 2026-10-26 03:16:56 snapshot_count 57 | last_success 2026-10-26T03:16:10Z +== demo-felhom (reports 2026-10-26 01:30–05:00 UTC; a line only where the count changes) + 2026-10-26 01:31:53 snapshot_count 58 | last_success 2026-10-25T03:15:37Z + 2026-10-26 03:16:53 snapshot_count 48 | last_success 2026-10-26T03:15:49Z +== demo-hp (reports 2026-10-26 01:30–05:00 UTC; a line only where the count changes) + 2026-10-26 01:31:57 snapshot_count 345 | last_success 2026-10-25T03:17:52Z + 2026-10-26 03:31:56 snapshot_count 359 | last_success 2026-10-26T03:18:02Z diff --git a/documentation/backlog/CLOSED-ITEMS.md b/documentation/backlog/CLOSED-ITEMS.md index 810ed037..9ae544a8 100644 --- a/documentation/backlog/CLOSED-ITEMS.md +++ b/documentation/backlog/CLOSED-ITEMS.md @@ -26,6 +26,12 @@ --- +## 2026-10-26 (evening) — R-435 read and closed (full text of the row: `git show 49557444:documentation/backlog/OPEN-ITEMS.md`) + +| Row | What | Closed | Evidence | +|---|---|---|---| +| **R-435** | **The snapshot-drop detector was blind to a single-app deletion; D7 (decision 191) made it mail an error when even one snapshot disappears outside a hub-opened clean-up window.** (P3) | CLOSED 2026-10-26 evening — the 2026-10-26 windows read from the hub's records and the mailbox (the box logs were lost to that day's restarts, said plainly): Tester 1 window 15 removed 21 (78 → 57) and the hub's next report fell 74 → 57; demo-felhom window 14 removed 15, report 58 → 48; each fall inside its window's removal; no drop event, no drop mail row, no drop mail (the same mailbox search finds that night's demo-hp refusal) | `audits/r435-window-read-2026-10-26/` | + ## 2026-10-26 (afternoon) — R-1295 fixed at the cause (ep0) and released (hub 0.172.0); R-1292 released (controller 0.345.0) (full text: `git show 69443d3c:documentation/backlog/OPEN-ITEMS.md`) | Row | What | Closed | Evidence | diff --git a/documentation/backlog/OPEN-ITEMS.md b/documentation/backlog/OPEN-ITEMS.md index 5134c446..2d052bfa 100644 --- a/documentation/backlog/OPEN-ITEMS.md +++ b/documentation/backlog/OPEN-ITEMS.md @@ -292,7 +292,6 @@ stopping line that lies. | **R-1202** | Monitoring & notifications | P3 | **A box whose clock is behind blames the hub and stops an app without telling anyone.** Rehearsal 2026-10-20 B6 #8: RTC set 2 years back (the OS raised it to 2026-04-13): the dashboard shows only „Hub nem elérhető" while the log says „x509: certificate … not yet valid: current time 2026-04-13…"; Paperless crash-looped and the box stopped it with a restore hold; the `app_stopped_unhealthy` event failed (hub unreachable), so neither the household nor the operator heard. After the real time came back the app stayed stopped until a Start (clear sentence, 1 min). | **OPEN** | — | say „the box's clock is wrong (it says )" when TLS fails with not-yet-valid/expired against a hub that answers; keep the stop event queued until the hub is reachable | CC | | **R-340** | Monitoring & notifications | P3 | **The new reachability check does not touch the surface that actually failed.** R-339 reports when the hub cannot READ ep0 — but the read it performs is the `usage` op, which is `proxmox-backup-manager` plus `df` over SSH, and therefore rides the **local API daemon**. The 2026-08-18 incident explicitly CLEARED that daemon: `proxmox-backup.service` was healthy throughout, and it was the **HTTPS proxy on 8007** that was wedged with a full accept queue. **So R-339's check would have returned green for all 9 h 37 m of that outage.** It closes the case where ep0 is unreachable *as a host*; it does not close the case that actually happened. This is not a defect in R-339 — it is the honest boundary of what it watches, recorded so a future reader does not mistake a green box gauge for a working off-site tier | **READY (M) — NEW 2026-08-18** | a tenantsync endpoint-script version bump (the op is added on ep0, so it needs the same version-gated rollout `ErrUsageUnsupported` already models) | Add a **health op** to `scripts/felhom-tenantsync.sh` that probes `https://127.0.0.1:8007/` on ep0 and reports the proxy's fd count and listen-queue depth, then surface it as a third signal. **Overlaps the connections spike (R-336's remaining half): both want the same observations from ep0, so whichever runs SECOND must reuse the first's evidence rather than re-measuring a protected machine twice** **REUSE, per this row's own instruction — the connections spike ran FIRST (2026-08-20) and already produced most of what the health op wants; do not re-measure a protected machine a third time.** Available in `audits/evidence-ep0-established-connections-2026-08-20/`: the proxy **fd count** and its type breakdown (`lsof` + `/proc//fd`), the **listen-queue depth** (`ss -lnt` — `Recv-Q 0`, `Send-Q 1024`), the **ESTAB/CLOSE-WAIT split**, the **per-peer** connection histogram, a **31-minute persistence diff** of full 4-tuples, and a **46.18 h** slope with Poisson bounds. What the health op would still add beyond these: a loopback `GET https://127.0.0.1:8007/` probe — the observation that distinguished "process problem" from "network problem" on 2026-08-18 and the one thing this spike did NOT take, because it is the surface R-339 cannot see. **And this spike sharpens what the op should report:** a rising **ESTAB** count is the live signal (CLOSE-WAIT was **0**, not merely flat), and per **R-344** the fd ceiling that matters may be the **agent's**, not only ep0's. | CC | | **R-388** | Monitoring & notifications | P3 | **PRODUCT DECISION (not a defect): the customer notification model is the wrong shape, and the settings page grows by one toggle per detector.** The operator's framing, recorded verbatim 2026-08-23: *"A customer should be notified only about things they can act on or are responsible for — the drive they unplugged, the storage they filled. **A failed backup is our incident, not theirs.** The intended shape is that we detect it, we tell them we noticed and are dealing with it, and they are not handed an error they cannot solve. The subscription should feel like being looked after, not like being on call."* Today's page is the opposite shape — one switch per detector, and it **grew from 12 to 15 in a single session** (one new alarm plus two compound toggles split into four). That growth is the argument, not an aside: a page that grows per detector keeps asking a household to make engineering decisions. | **READY** — **2026-10-12 evening: slice 1 delivered** (operator Q1/Q2 „as picked", `09` §3 decisions 234–235): the page shows three group switches; the per-detector switches and the cooldown sit under „Részletek"; an „egyedi" group is saved back unchanged; the default list fills groups 1 and 3 (households with no saved list), group 2 stays „egyedi" (`app_start_failed` off, R-329). Tests red-proved. controller 0.309.0, delivered 2026-10-12 18:08 to demo-hp, demo-felhom and Tester 1 (`controller-0.309.0-delivery.txt`). **READY** — **2026-10-12: the design is written** (`08` §8.1): three group switches („A gépem és a meghajtóim", „Az alkalmazásaim", „Amit mi intézünk") mapped onto today's 18 detectors; option A picked; slice 1 changes no wire. Two questions for the operator (group 3 default; the cooldown field). **READY** — operator ruling 2026-10-12 (S5, `09` §3 decision 200): design now (one page: options, a pick, the first slice), build in slices later. **OPEN — DIRECTION, operator's call** | a decision on scope; nothing here is a bug | Slice 2 (hub): group 3's mails say „we noticed X and are handling it" instead of the raw error | CC (+ operator: two answers) | -| **R-435** | Monitoring & notifications | P3 | **The snapshot-drop detector is blind to a single-app deletion — the exact shape the box can produce.** `snapshotDropFraction = 0.5` and `snapshotDropFloor = 5` (`hub/internal/monitor/offsite.go`) require a fall of MORE than half the previous count. demo-hp's baseline is **69** across 9 apps, so ~35 snapshots must go before it speaks; **one app's tag is ~9 and is invisible.** `offbox.go:1388` runs `forget --prune` **grouped by host,tags** — a per-tag wipe is precisely the shape a faulty retention or a targeted deletion produces. **This is deliberate, not accidental:** the constant's own comment argues the insensitivity, and *"a detector that cries wolf is switched off within a fortnight"* is a lesson this project paid for. **So this row is NOT a demand to lower the threshold.** It is a demand that the blind spot be written where the operator reads it, because "an unexplained fall is noticed within a day" (R-431, and `STATUS.md`) is true only of falls above half. **Discovered by arithmetic while planning the drill's Phase 2/3 pairing, which could not have worked:** Phase 2 deletes one app and Phase 3 expects the alarm to fire. **LIMITATION NOW WRITTEN INTO THE ALARM'S OWN DOCUMENTATION, hub v0.111.1** — the comment above `snapshotDropFraction` in `hub/internal/monitor/offsite.go` now states what the detector does NOT see, with the demo-hp arithmetic and the `forget --prune` grouping that makes the blind spot sit on the most likely single-app failure. **It also says explicitly that the numbers must NOT be lowered to "fix" this** and that per-app detection needs a SECOND signal keyed on the per-tag count. **The row stays OPEN because documenting a blind spot is not covering it** — and because `STATUS.md` and R-431 both still say "noticed within a day", which is true only of falls above half. **-- 2026-10-08 design:** `audits/day-2026-10-08/design-R-435.md` — the box's key can no longer delete (decisions 68–69); deletion through any other credential still needs >50 % to alarm. Question D7 on STATUS's decision sheet. **-- 2026-10-08 14:16 operator ruling D7 (`09` §3 decision 191):** yes — option C, an error mail when even one snapshot disappears outside a hub-opened clean-up window (pinned tiers). | **VERIFY** — **2026-10-12 read: not provable today.** No mail for a snapshot drop reached the operator since 2026-10-11 (Gmail), but the window itself could not be read: no hub page shows `offsite_windows`, Tester 1's controller log restarted with 0.308.0 at 13:49Z, and the guest-agent path to its VM did not answer. Re-dated after the next weekly clean-up. **VERIFY — 2026-10-09: DELIVERED in hub 0.144.0. Live proof NOT run: a window is granted only when the box asks for one, and Tester 1's weekly clean-up is next due ~2026-10-12 (last window 2026-10-05); prove it then (no alarm inside the window; the hub's window row as control).** **VERIFY — built on hub main 2026-10-08 (D7, decision 191), ships tomorrow; closes after the 9202 proof (a hand-granted window removes N, no alarm; the hub's window row as the control).** **OPEN — documented in code v0.111.1; the coverage gap itself is unclosed** **2026-10-05 (burn-down night): NEEDS A DESIGN.** Covering one-app deletions needs per-app snapshot counts from the controller and a per-tag threshold measured on real counts — two repos, a mechanism nobody has measured. **2026-10-20 03:5x UTC: due date moved 10-20 → 10-21** — the night session that reached it was not briefed for this read (a Tester 1 log and the mailbox); the window row and the mails stay readable a day later. **2026-10-21: due date moved 10-21 → 10-27** — Tester 1's weekly window was 2026-10-19 02:15:53Z (its box log, 2026-10-21 02:16), but both channels for its counts are gone: Tester 1's controller restarted 2026-10-20 08:51Z (the floor) and the hub pod 2026-10-20 06:03Z, so the before/after lines no longer exist. The next window is ~2026-10-26 02:15Z; read the box log and the hub log the next morning, BEFORE any restart. | — | 2026-10-20: read Tester 1's controller log (window opened/closed, count before/after) and the operator mailbox (no drop alarm) the morning after its weekly clean-up | CC | | **R-724** | Monitoring & notifications | P3 | **[P3-LOW] The status pages disagree with each other in small ways a household notices.** MEASURED 2026-09-29 on a fresh box: Beállítások reads „Mentés ütemezés 02:30 / 03:00" while Biztonsági mentés says 02:30 / 03:30 / 04:15 / 04:30–08:30; Beállítások shows a raw `2026-09-29T19:22:30Z`; its „Helyi cím (LAN)" and „Átjáró" read „nem állapítható meg" on the page the household is asked to read out for remote help; the backups overview still says „Következő mentés — 0 órája" (the age of the LAST run, under the word "next" — noted 2026-09-14, never filed); the dashboard shows the backup at 19:33 where the backup pages say 21:33 (R-500, still reproducing). **FIXED 2026-09-30 (controller v0.283.0):** Beállítások shows the real schedule and a local time; the dashboard's last backup is local time (R-500); „az előző N órája készült" replaces „0 órája". **NARROWED — remaining:** „Helyi cím (LAN)" / „Átjáró" read through the file-sharing container, so a box without it says „nem állapítható meg" — not a text fix (the read needs another path). | **NARROWED — the LAN/gateway read only; owner: CC** **2026-10-06 night: confirmed not a controller-only fix** — the only host-network container is samba (`infra/samba.go:123`) and the agent's local API has no guest-network route; the fix is a new agent route (e.g. the PVE lxc interfaces read) + a controller reader — a two-repo design. | — | — | CC | | **R-285** | Monitoring & notifications | P4 | **A planned, supervised reinstall pages the operator as if the machine had died — there is no notion of expected downtime anywhere.** During the 2026-08-09 rehearsal the hub sent, all `status: sent` to the operator channel: `host_stale` 08:58 UTC, `node_stale` 09:00, **`host_down` 09:28 (error)**, **`node_down` 09:30 (error)**, `host_leaf_changed` 09:31, `host_recovered` 09:31, `node_recovered` 09:34, `offsite_delivery_stuck` 09:34 — eight operator mails for work that was deliberate, attended and announced. **This is the OPPOSITE gap from the one R-281 filed:** the alarms are not missing, they are indiscriminate. `host_stale` at 30 min and `host_down` at 60 min (`monitor/host_staleness.go:22-23`, `downAfter = 2 * threshold`) cannot distinguish a wiped-on-purpose box from a dead one, and `host_leaf_changed` firing on a reinstall is correct-but-expected. **Note the interaction with the mute used on 2026-08-09 evening:** blocking a customer silences everything, so today the only two settings are *page me for planned work* and *tell me nothing at all*. **What is owed is a middle:** a maintenance window, or an operator-set expected-downtime flag, that suppresses staleness and leaf-change while leaving genuine faults audible | **READY (M) — NEW 2026-08-09** | — | The evidence is the operator's mailbox plus `events`/`notification_log` for 2026-08-09 | CC | | **R-1005** | Monitoring & notifications | P4 | **A recovery mail says how long the box was „stale", not how long it was gone: after a 51-minute power cut demo-hp's `host_recovered` read „was stale for 8m" and `node_recovered` „23m".** An operator reading only the recovery mail under-reads the outage (`audits/night-power-2026-10-13/` R6). Same kind, the other way: the off-site mail of 2026-10-14 02:18 was titled „3 of 3 apps failed to back up (offsite run)" while 11 other apps were backed up in that run — only the 3 flagged apps were counted. | **READY** — filed 2026-10-14 | — | CC: add the time since the last report before the gap to both recovery messages, and count every app of the run in the off-site subject, with a test that asserts each text; next hub release | CC | @@ -389,7 +388,6 @@ stopping line that lies. the R-row. Duplicating them here would create the second source this design avoids. --> | item | due (UTC) | what to measure | |---|---|---| -| R-435 | 2026-10-27 | Tester 1's weekly off-site clean-up ran inside a hub window with no drop alarm (box log + mailbox); detail in the R-435 row | | R-1250 | 2026-10-27 | the released line hold, live: a seeding qBittorrent on demo-hp (peer DooPlex's, operator yes 2026-10-25) through the host's due window; the line value and the limit back; detail in the R-1250 row | | R-1293 | 2027-03-29 | the spring clock change: the hub's 02:00 snapshot and the 02:30 push on 2027-03-28 (02:00–03:00 does not exist) — which file each push took; detail in the R-1293 row | | R-1228 | 2026-10-30 | D35 (yes, after the release week): start moving the website + installer to Cloudflare; detail in the R-1228 row |