docs(report): v0.139.0 live verification — 2s save-to-hub round-trip proven on 9201
Out-of-cycle pushes at 17:42:19/17:42:34Z (quiet-window + min-interval pacing exactly as designed, trailing edge carried the final state); scheduled 15-min cycle unaffected (17:49:00Z tick on both ends). Red-proof outcomes and the NOT-yet-live-validated list recorded.
This commit is contained in:
@@ -1,116 +1,145 @@
|
|||||||
# REPORT — felhom-controller v0.138.0: escrow "awaiting hub confirmation" waiting state
|
# REPORT — v0.139.0: immediate out-of-cycle hub report on user actions (Direction 1)
|
||||||
|
|
||||||
**Task:** Diagnose the stuck "Helyreállítási kód szükséges" banner after a completed escrow ceremony
|
**Date:** 2026-07-16 · **Session:** Claude Code (spec: "Immediate out-of-cycle hub report on user
|
||||||
on the demo box; add the post-ceremony waiting-state UX; ship the hub stale-clear fix **only if**
|
actions (Direction 1)") · **Repo:** felhom-controller only (hub/agent/catalog untouched, as specced)
|
||||||
Phase-0 diagnosed Hypothesis B.
|
|
||||||
|
|
||||||
**Shipped:** controller **v0.138.0** (Part 1, unconditional). **Hub: NO change** (Phase-0 = A, and
|
## Baselines used
|
||||||
Hypothesis B verified false). felhom-agent untouched.
|
|
||||||
|
|
||||||
---
|
| Repo | Base commit | Version before → after |
|
||||||
|
|---|---|---|
|
||||||
|
| felhom-controller | `8f3564c` (matched the spec's `8f3564c1`) | v0.138.0 → **v0.139.0** |
|
||||||
|
|
||||||
## Phase 0 — DIAGNOSIS (read-only). Verdict: **A (report-cycle lag)** — already resolved on the box.
|
## What shipped
|
||||||
|
|
||||||
The banner renders while `Offbox.EscrowState != "escrowed"`. The pending→escrowed flip happens only
|
One generic, debounced out-of-cycle report trigger (`report.Trigger`) on the proven outbound push
|
||||||
in `report.EscrowAutoConfirmer.Reconcile` on a report ACK, on hash-match between the ACK's
|
channel; the 15-min `hub-report` cycle untouched as the reconciliation backbone.
|
||||||
`restic_pw_sha256` and the local repo password. The observed stuck banner was the ~15-min gap between
|
|
||||||
a completed ceremony and the next ACK.
|
|
||||||
|
|
||||||
**Evidence — demo box `felhom-controller` logs (guest 9201, running 0.136.0):**
|
- **`controller/internal/report/trigger.go` (new):** buffered-1 signal chan + single worker
|
||||||
```
|
(shape: hub `wgsync/reconciler.go`). `Fire()` non-blocking; worker = quiet 2 s → drain →
|
||||||
2026/07/16 16:13:31 [INFO] [web] escrow ceremony started via wizard (job escrow-1784218411576550074)
|
min-interval 15 s → ONE fire of an opaque `func() error`. Coalesce-and-eventually-fire
|
||||||
2026/07/16 16:13:39 [INFO] [web] escrow recovery code claimed (one-shot; not logged)
|
(trailing edge) — deliberately NOT the `internal/sync` refuse-debounce. No own retries
|
||||||
2026/07/16 16:27:58 [INFO] [report] Hub report pushed successfully (2992 bytes)
|
(Pusher owns 3×5 s); fire error → one WARN, loop continues; exits on ctx cancel.
|
||||||
2026/07/16 16:27:58 [INFO] [escrow-confirm] hub-verified: the escrow covers the current repo password (hash d517ce7f9982…) — EscrowState auto-confirmed escrowed; offsite runs enabled
|
- **`controller/cmd/controller/main.go`:** ONE canonical fire closure (BuildReport + Claimed +
|
||||||
```
|
Push), built only when `hubPusher != nil && cfg.Hub.Enabled`; `trigger.Run` under the process
|
||||||
- Ceremony claimed `16:13:39`; the **very next** `hub-report` ACK at `16:27:58` (~14 min later)
|
ctx; replaced the raw per-fire goroutine behind `apiRouter.SetReportPushTrigger` (v0.70.0 geo
|
||||||
flipped pending→escrowed via hash-match (`d517ce7f9982…`). One INFO confirm line, no mismatch
|
seam kept, now debounced); new `webServer.SetReportTrigger(trigger.Fire)`.
|
||||||
warning, no withheld-hash gap.
|
- **`controller/internal/api/router.go`:** `reportPushNow()` added after success in deploy,
|
||||||
- **Current box state:** `settings.json` → `"escrow_state": "escrowed"` (verdict A resolved itself;
|
remove, delete (geo save/sync already had it).
|
||||||
the box is confirmed; `OffboxRunnable()` true).
|
- **`controller/internal/web`:** `SetReportTrigger`/`reportTriggerNow` seam (server.go, nil-safe,
|
||||||
|
mirrors `api.Router.reportPushNow`); fired AFTER the successful local commit in:
|
||||||
|
escrow recovery-code claim (escrow_handlers.go — the headline), notification-prefs save +
|
||||||
|
app-email toggle (handlers.go; password handler untouched — it is a separate handler),
|
||||||
|
offsite target config (offbox_handlers.go `offboxConfigHandler`) **and** per-app offsite
|
||||||
|
toggle (`offboxToggleHandler`), customer claim completion (claim.go).
|
||||||
|
- Docs: CHANGELOG (v0.139.0 top entry), CONTEXT.md decision ("Direction 1 shipped; Direction 2
|
||||||
|
pending SPIKE-immediate-sync-transport"), README report section rewritten, REUSE.md
|
||||||
|
(§1 helper row + §2 coalescing-vs-refuse pattern pair).
|
||||||
|
|
||||||
**Hypothesis B (hub never clears stale on upload) — verified FALSE, so NO hub change:**
|
### Handler-name mapping vs the spec (per §Part 3 "wire the real one")
|
||||||
- `store.SaveHostEscrow` (the escrow **upload** sink, `handler.go:1083`) already clears stale on a new
|
|
||||||
blob: `INSERT … ON CONFLICT(host_id) DO UPDATE SET … stale_at = NULL` (`store.go:2084`).
|
|
||||||
- The ACK only withholds the hash **while `stale_at` is set** (`store.go:2150`: `if staleAt != ""`).
|
|
||||||
- So a re-issue→re-ceremony cycle recovers on its own; the only thing not emitted is a cosmetic
|
|
||||||
`escrow_refreshed` event — out of scope (Part 2 gated on B, which does not hold).
|
|
||||||
|
|
||||||
**Hypothesis C (upload silently failed):** ruled out — the box reached escrowed via a hash-bearing
|
| Spec name | Real handler wired |
|
||||||
ACK, which requires the fresh blob + hash to be present on the hub.
|
|---|---|
|
||||||
|
| "settings POST handler(s) in web/handlers.go" | `settingsNotificationsHandler` + `settingsAppEmailHandler` (both preference/notification-type; `settingsPasswordHandler` is a separate handler → cleanly excluded) |
|
||||||
|
| "offbox_handlers.go toggle handler" | BOTH `offboxConfigHandler` (target enable/disable) and `offboxToggleHandler` (per-app Távoli-mentés flag) — the spec's "enable/disable" is the config handler; the literal "toggle handler" is per-app; both are hub-visible state |
|
||||||
|
| "api-router deploy/remove endpoints" | `deployStack`, `removeStack`, `deleteStack` (both removal variants) |
|
||||||
|
|
||||||
**Operational note:** the demo Proxmox host key changed since the last session (box reprovisioned for
|
## Commits
|
||||||
the N100 customer-zero run). Refreshed `known_hosts` (`accept-new`) before any read — expected for the
|
|
||||||
demo host, not a security event.
|
|
||||||
|
|
||||||
---
|
| Hash | Content |
|
||||||
|
|---|---|
|
||||||
|
| `fe9266f` | feat(report): v0.139.0 — trigger engine + all wiring + tests + docs (15 files, +501/−14) |
|
||||||
|
| (this commit) | docs(report): REPORT.md live-validation evidence |
|
||||||
|
|
||||||
## Part 1 — controller v0.138.0 (the waiting state)
|
## Tests & red-proofs
|
||||||
|
|
||||||
1. **Persisted stamp.** New `settings.OffboxTarget.CeremonyCompletedAt` (`ceremony_completed_at`,
|
Green gate `go build ./... && go vet ./... && go test ./...` — all packages pass **except 6
|
||||||
RFC3339). SET on a successful recovery-code **claim** (`web/escrow_handlers.go`, only while still
|
pre-existing Windows-environment failures** (appexport disk-free df=0 ×4, stacks
|
||||||
pending; best-effort — a stamp failure never fails the claim, the code is already revealed and the
|
`TestMigrate_PaperlessShape_ScopeApp`, web `TestFab_SelectionsRideBothStartPipelines`) —
|
||||||
blob already uploaded). ZEROED on the pending→escrowed flip — the auto-confirmer `Flip` closure
|
**verified failing identically on base `8f3564c`** via `git stash` + rerun. Changed packages:
|
||||||
(`cmd/controller/main.go`) **and** the deprecated manual confirm (`web/offbox_handlers.go`).
|
`internal/report` ok, `internal/api` ok, `internal/web` ok (except the listed pre-existing fab
|
||||||
Persisted ⇒ survives a controller restart mid-wait.
|
test). Design gates (template_id, emoji, native_confirm, offbox_rename): all OK. Test functions:
|
||||||
2. **The pick.** `web/handlers.go`: `offboxCeremonyWaitState(t)` → (awaiting, timedOut);
|
629 total after (+8 new).
|
||||||
`escrowCeremonyGraceWindow = 35m` (2 report cycles + slack, named). Falls back to the plain pending
|
|
||||||
CTA when escrowed, unstamped, or the stamp is unparseable.
|
|
||||||
3. **Card branch.** `backups_remote.html`: one new escrow-card branch ahead of the existing chain —
|
|
||||||
**info (blue `--blue`)** "Helyreállítási kód létrehozva … megerősítésre vár, legfeljebb 15 perc",
|
|
||||||
degrading to **warn** "A megerősítés nem érkezett meg a várt időn belül …" + re-ceremony CTA past
|
|
||||||
the window. Existing pending / stale (Scenario F) / escrowed branches untouched.
|
|
||||||
4. **Wizard final screen.** `backups_escrow.html` "7. Befejezés" step gains the **"Mi történik
|
|
||||||
ezután?"** info note (generated / sent to the hub / bounded ≤15-min wait) — the wizard finishes to
|
|
||||||
`/backups/remote`, so the customer lands directly on the awaiting card.
|
|
||||||
|
|
||||||
**NOT built (as instructed):** no scheduler rework; no manual report-trigger. *Observation:* no
|
New tests (`internal/report/trigger_test.go`, `web/report_trigger_seam_test.go`,
|
||||||
pre-existing manual/API report-trigger seam was found (report push is the scheduler `hub-report` job),
|
`api/report_trigger_nilsafe_test.go`):
|
||||||
so the one-liner "fire a report right after the ceremony" option was correctly skipped.
|
|
||||||
|
|
||||||
## Part 2 — hub v0.57.1: **NOT shipped** (Phase-0 = A, Hypothesis B false; see diagnosis above).
|
| Group | Test | Result |
|
||||||
|
|---|---|---|
|
||||||
|
| A | `TestTrigger_SingleFireExactlyOnePush` (1 fire → exactly 1 push) | PASS |
|
||||||
|
| A | `TestTrigger_FireNonBlocking` (100× Fire < 1 ms each, buffer full, no worker) | PASS |
|
||||||
|
| B | `TestTrigger_BurstCoalescesTrailingEdge` (10 fires → 1..2 pushes, last push after last fire) | PASS |
|
||||||
|
| C | `TestTrigger_FireErrorWorkerContinues` (error isolated, next fire pushes) | PASS |
|
||||||
|
| §8 | `TestTrigger_CancelDuringWaitExitsPromptly` (<1 s exit mid-wait, 0 fires) | PASS |
|
||||||
|
| D | `TestReportTriggerNow_NilSeamIsNoOp` (web) + `TestReportPushNow_NilSeamIsNoOp` (api) | PASS |
|
||||||
|
| — | `TestReportTriggerNow_FiresAfterSuccessfulCommitOnly` (real offbox-toggle handler: 0 on refused save, 1 on committed save) | PASS |
|
||||||
|
|
||||||
---
|
**Red-proof B (run→fail→revert):** replaced `Run` with the naive `for { <-signal; fire() }` loop
|
||||||
|
(every signal straight to fire) → `TestTrigger_BurstCoalescesTrailingEdge` FAILED with
|
||||||
|
**"10-fire burst produced 10 pushes, want 1..2"** → reverted → green.
|
||||||
|
|
||||||
## Green gates & tests
|
**Red-proof C (run→fail→revert):** added `return` after the fire-error WARN (worker dies on
|
||||||
|
first error) → `TestTrigger_FireErrorWorkerContinues` FAILED with **"fire count = 1, want >= 2"**
|
||||||
|
(the subsequent fire never pushed) → reverted → green.
|
||||||
|
|
||||||
- `go build ./...` OK · `go vet ./...` OK · `go test ./...` **0 failures**.
|
## Deploy (guest 9201, bootstrap flow)
|
||||||
- Design gates OK: `template_id_gate`, `emoji_gate`, `native_confirm_gate`, `offbox_rename_gate`.
|
|
||||||
- New test `web/escrow_wait_state_test.go` — 8-case truth table + mutual-exclusion invariant.
|
|
||||||
**Red-proof (run→fail→revert):** dropped `t.EscrowState == "escrowed"` from the early-return guard →
|
|
||||||
`escrowed clears the wait` case FAILED (`awaiting=true, want false` — the interim card would resurface
|
|
||||||
after the healthy state) → reverted → green.
|
|
||||||
|
|
||||||
## Scenarios
|
- Built + pushed `gitea.dooplex.hu/admin/felhom-controller:0.139.0` on 180
|
||||||
|
(digest `73fb3f57…`, 145 MB).
|
||||||
|
- Deployed: pull + `/etc/felhom-controller-image` + `systemctl restart
|
||||||
|
felhom-controller-bootstrap.service`.
|
||||||
|
- Verified: `docker ps` → `…felhom-controller:0.139.0 Up … (healthy)`; startup clean; startup
|
||||||
|
report `17:34:04Z` "Hub report pushed successfully (2953 bytes)" ↔ hub pod `19:34:04 Received
|
||||||
|
report from demo-felhom (2953 bytes)` (hub logs are CEST).
|
||||||
|
|
||||||
- **S-A (waiting state):** ceremony completes → info card shows immediately (stamp set on claim);
|
## Live validation (real-UI-flow; method stated per doctrine)
|
||||||
confirming ACK zeroes the stamp AND sets escrowed → escrowed branch wins → healthy card. ✔ (logic +
|
|
||||||
live: box is escrowed).
|
|
||||||
- **S-B (timeout):** stamp aged past `escrowCeremonyGraceWindow` with state still pending → warn +
|
|
||||||
re-ceremony CTA. ✔ (unit: `stamped past window → timed out`, `at boundary → timed out`).
|
|
||||||
- **S-C (restart mid-wait):** stamp is persisted in `settings.json` → the info card survives a restart.
|
|
||||||
✔ (persisted field; unit covers the stamped-pending path).
|
|
||||||
- **S-D (hub, if B):** N/A — Phase-0 = A, no hub change.
|
|
||||||
|
|
||||||
## Deploy & live verification
|
**Method:** browser login was not possible (dashboard password is customer-owned; the deploy also
|
||||||
|
invalidated sessions, and entering credentials via browser automation is out of bounds for CC), so
|
||||||
|
per the repo doctrine the **exact endpoints the UI invokes** were driven server-side from 180 with
|
||||||
|
curl — real login POST → session cookie → CSRF token from the real page → real form POSTs. The
|
||||||
|
password was read into a shell var from Viktor's out-of-band store (never echoed/logged; length 13
|
||||||
|
only). Residual gap vs a browser: client-side rendering only — no server logic skipped.
|
||||||
|
|
||||||
- Committed to `main` (`1203321`); image `gitea.dooplex.hu/admin/felhom-controller:0.138.0`
|
**Action:** `bookstack` per-app Távoli-mentés toggle OFF → (6 s later) → ON — value-identical end
|
||||||
built+pushed on 180 (digest `sha256:49f9474c…`).
|
state (`offbox: true` confirmed in settings.json afterwards); both POSTs 302 (success flash).
|
||||||
- **Update train 0.136.0 → 0.138.0** delivered cleanly to guest 9201 (0.137.0 was built but never
|
|
||||||
deployed to the box; the bootstrap pull jumped straight to 0.138.0). `docker ps`:
|
|
||||||
`…felhom-controller:0.138.0 Up (healthy)`; startup clean (`Web UI listening on :8080`,
|
|
||||||
`Starting scheduler with 13 jobs`).
|
|
||||||
- **Live end-state (matches the task target):**
|
|
||||||
- `settings.json` → `escrow_state: "escrowed"` (Phase-0 A already flipped it; no `ceremony_completed_at`
|
|
||||||
present, correct for an already-escrowed box) → renders the healthy **"A helyreállítási kód letétbe
|
|
||||||
helyezve"** branch (unchanged).
|
|
||||||
- offbox `enabled: true` + escrowed + Hetzner storagebox target ⇒ **`OffboxRunnable()` true**.
|
|
||||||
- New template strings confirmed in the deployed binary (embedded templates): "megerősítésre vár" ×2
|
|
||||||
(remote card + wizard note), "A megerősítés nem érkezett meg" ×1, "Mi történik ezután" ×1.
|
|
||||||
- **Not live-rendered:** the awaiting/timeout cards themselves — they require an in-flight pending
|
|
||||||
ceremony, and re-running the ceremony is Viktor's supervised flow (would un-escrow → re-escrow the
|
|
||||||
live box). S-A/S-B/S-C are covered by the unit truth table + the persisted-field design; the card
|
|
||||||
markup is byte-identical to what the unit-verified booleans gate.
|
|
||||||
|
|
||||||
**NOT done — Viktor's click:** the first "Távoli mentés most" (first offsite run) is the customer's, per
|
| Event | Controller (UTC) | Hub pod (CEST) | Delta |
|
||||||
the task. CC stops at escrowed-verified.
|
|---|---|---|---|
|
||||||
|
| Toggle OFF POST | 17:42:17 | — | — |
|
||||||
|
| Out-of-cycle push #1 | **17:42:19** "Hub report pushed successfully (2968 bytes)" | **19:42:19** "Received report from demo-felhom (2968 bytes)" | **2 s after the save** (= quiet window) |
|
||||||
|
| Toggle ON POST | 17:42:23 | — | — |
|
||||||
|
| Out-of-cycle push #2 (trailing) | **17:42:34** (2961 bytes) | **19:42:34** (2961 bytes) | 15 s after push #1 (= min-interval pacing; last state carried) |
|
||||||
|
|
||||||
|
Round-trip user action → hub: **2 seconds** (previously up to ~15 min). The second push also
|
||||||
|
live-demonstrates Scenario B's coalescing/pacing (two fires 6 s apart → exactly 2 pushes,
|
||||||
|
15 s spaced, trailing edge).
|
||||||
|
|
||||||
|
**Scheduled cycle unaffected:** the next 15-min `hub-report` tick fired on schedule at
|
||||||
|
**17:49:00Z** (≈15 min after the 17:34:04Z startup report; the two out-of-cycle pushes at
|
||||||
|
17:42 did NOT perturb it) — controller "Hub report pushed successfully (2982 bytes)" ↔ hub
|
||||||
|
`19:49:00 Received report from demo-felhom (2982 bytes)`.
|
||||||
|
|
||||||
|
## NOT yet live-validated (unit-covered; shared seam proven live)
|
||||||
|
|
||||||
|
- **Escrow recovery-code claim call site** — deliberately NOT exercised (the demo box is
|
||||||
|
escrowed; un/re-escrowing is Viktor's supervised flow). Covered by unit tests + the identical
|
||||||
|
`reportTriggerNow` seam proven live via the offbox toggle. Expected effect at Viktor's next
|
||||||
|
wizard pass: the "megerősítésre vár" card flips in seconds.
|
||||||
|
- **App deploy/remove call sites** — not exercised live (a deploy/remove on the demo box is not
|
||||||
|
harmless); same `reportPushNow` seam as geo, now trigger-backed.
|
||||||
|
- **Customer claim + notification-prefs + app-email call sites** — not exercised live (claim
|
||||||
|
would reset Viktor's password; the notifications form on this box has an empty stored email —
|
||||||
|
an "identical re-save" is impossible without picking an email, and the v0.137.0 wipe guard
|
||||||
|
refuses empty-email-with-events anyway).
|
||||||
|
|
||||||
|
## Observations (out of scope — documented, not acted on)
|
||||||
|
|
||||||
|
- **BuildReport call-site duplication:** the `BuildReport(...) + r.Claimed = sett.GetClaimed()`
|
||||||
|
pair still exists at the scheduled job, the startup report, and the debug callback (per spec
|
||||||
|
§Part 2.1 only the trigger closure was centralized).
|
||||||
|
- **Copy soften candidate (post-live-proof):** `backups_remote.html` "legfeljebb 15 perc" →
|
||||||
|
"általában néhány másodperc" is now a truthful later one-liner (spec §Part 3 note).
|
||||||
|
- **`offboxConfirmEscrowHandler` (legacy manual escrow confirm)** also flips hub-relevant state
|
||||||
|
but was not in the Viktor-approved wiring list — a candidate for a later one-liner.
|
||||||
|
- **Windows green gate:** 6 pre-existing environment failures (df=0/rsync-shape); the Linux
|
||||||
|
build on 180 is the authoritative gate for those packages.
|
||||||
|
|||||||
Reference in New Issue
Block a user