From 7d64038f02af00d4882bd834907b75f4d0729143 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Sat, 17 Oct 2026 23:31:34 +0200 Subject: [PATCH] Hub v0.158.0 code (built, NOT deployed): agent-only vouch, R-895 snapshot alarms, the hub's own 90-day access log (R-1140 A); installer --rotate-recovery-only (R-1141); 02/03/05/09 + break-glass Hub: the R-120 golden guard judges only a CHANGED golden selection; offsite_snapshots_vanished / _unexplained (operator-only, hub-origin) on the 07:10 listing; internal/accesslog writes path-only lines to /data/access-log, 90 days. Installer: --rotate-recovery-only runs step 4b alone (rides the next installer tag). 03: the orphan check runs after a failed backup (agent 6545ccc). 02: the allow-list is empty, appdata_folders (controller v0.329.0). All red-proofed. --- .../architecture/02-controller-module-map.md | 21 +- documentation/architecture/03-host-agent.md | 2 +- .../architecture/05-hub-architecture.md | 19 +- .../architecture/09-update-architecture.md | 8 +- documentation/runbooks/break-glass.md | 17 +- hub/CHANGELOG.md | 29 ++ hub/cmd/hub/main.go | 10 +- hub/cmd/hub/r1140_wiring_test.go | 53 +++ hub/internal/accesslog/accesslog.go | 396 ++++++++++++++++++ hub/internal/accesslog/accesslog_test.go | 235 +++++++++++ hub/internal/api/handler.go | 5 + hub/internal/api/r1140_accesslog_test.go | 61 +++ hub/internal/api/r895_events_test.go | 22 + hub/internal/notify/dispatcher.go | 5 + hub/internal/offsitekeys/offsitekeys_test.go | 5 + hub/internal/offsitekeys/service.go | 22 +- hub/internal/offsitekeys/snapshot_watch.go | 210 ++++++++++ .../offsitekeys/snapshot_watch_test.go | 250 +++++++++++ hub/internal/offsitekeys/snapshots.go | 8 + hub/internal/store/offsite_snapshots.go | 96 +++++ hub/internal/web/agent_only_vouch_test.go | 82 ++++ hub/internal/web/configs.go | 20 +- hub/internal/web/server.go | 3 + hub/internal/web/tokens.go | 2 + scripts/CHANGELOG.md | 13 + scripts/felhom-host-install.sh | 195 ++++++--- scripts/hostinstall-mode-harness.sh | 101 ++++- 27 files changed, 1813 insertions(+), 77 deletions(-) create mode 100644 hub/cmd/hub/r1140_wiring_test.go create mode 100644 hub/internal/accesslog/accesslog.go create mode 100644 hub/internal/accesslog/accesslog_test.go create mode 100644 hub/internal/api/r1140_accesslog_test.go create mode 100644 hub/internal/api/r895_events_test.go create mode 100644 hub/internal/offsitekeys/snapshot_watch.go create mode 100644 hub/internal/offsitekeys/snapshot_watch_test.go create mode 100644 hub/internal/store/offsite_snapshots.go create mode 100644 hub/internal/web/agent_only_vouch_test.go diff --git a/documentation/architecture/02-controller-module-map.md b/documentation/architecture/02-controller-module-map.md index e237852e..165acc50 100644 --- a/documentation/architecture/02-controller-module-map.md +++ b/documentation/architecture/02-controller-module-map.md @@ -738,7 +738,8 @@ this app's service has EXACTLY that setting on the allow-list: `privileged`, `ca `include`, ANY `extends`, a `provider` service, `post_start`/`pre_stop` hooks, an `env_file`/`configs`/`secrets` file outside the stack dir, a named volume with `driver`/`driver_opts`/`external`/`name`, a `${VAR}` in any of those keys, and binds: the Docker socket anywhere, mount propagation, a `${VAR}` in a bind's options, and any source outside the -data roots the box itself gives — `${HDD_PATH}/appdata/`, `${USERDATA_PATH}`, `${IMPORT_PATH}` (a bind source may use +data roots the box itself gives — `${HDD_PATH}/appdata//` (v0.329.0, R-1142), `${USERDATA_PATH}`, +`${IMPORT_PATH}` (a bind source may use only those variables, as its leading token; each root must lie under `/mnt/felhom-drives/` or the system data path; on the box a source is judged where it really points, through its nearest existing ancestor, so a symlink cannot carry it out). @@ -747,9 +748,17 @@ out). Gitea — the threat R-971 names (whoever can push to the catalog can take every guest) — cannot add to it; a new entry needs a controller release. An entry is app + service + exact setting, and holds only while that service runs the entry's image REPOSITORY (a literal reference), with the image's own entrypoint and command, and the exact -`healthcheck.test` the entry names — so a push cannot keep the allowed right and change what runs with it. Today: one -entry, homepage's read-only Docker socket (the survey of all 123 catalog files found nothing else, -`audits/agent-allowlist-rotation-2026-10-17/P2/survey.md`). The catalog's CI gate `check-privileges.py` mirrors the +`healthcheck.test` the entry names — so a push cannot keep the allowed right and change what runs with it. **Since +v0.329.0 the list has NO entry** (R-981): homepage's read-only Docker socket — the one entry of v0.328.0 — served no +Felhom feature (its rendered `docker.yaml` is empty, nothing carries `homepage.*` labels; measured on demo-hp, +`audits/night-2026-10-18/P1/`), so the template dropped it and so did the list. The entry-binding rules stay pinned on a +test list, so a future entry is held to them. **The app's own folder (R-1142):** the list's `appdata_folders` map names +an app's folder under `${HDD_PATH}/appdata/` when it is not the app's name — one entry, `paperless-ngx → paperless` (the +survey of every template, the drill catalog and the three test boxes found no other). It is compiled in with the list, +because the catalog is the threat and must not name the folder; an app NAMED like a folder the map gives to another app +gets no `HDD_PATH` root, and one folder for two apps refuses to load. `USERDATA_PATH` is always the controller's own +derivation from `HDD_PATH`, never the app's env — a deploy field a catalog push adds would otherwise name any folder +(both found by the security review of the pushed commit, 2026-10-18). The catalog's CI gate `check-privileges.py` mirrors the check with a byte-identical copy of the list (pinned from both sides); the BOX is the authority. **What a refusal does.** Nothing is written. A refused correction or update leaves the app on its last good compose, @@ -760,8 +769,8 @@ that cannot read the compose refuses. The sync never copies a catalog template n **Out of scope, stated.** The controller's own infra stacks (traefik, cloudflared, filebrowser, samba) and its override files (setup gate, family gate, install hold, media library) are rendered by the controller, not the catalog. Published -host ports are not a class (crafty-controller's game ports). Known limit: under `${HDD_PATH}/appdata/` one app can -name another app's folder (a per-app rule needs a name map — paperless-ngx keeps `appdata/paperless`), R-1142. +host ports are not a class (crafty-controller's game ports). `${USERDATA_PATH}` and `${IMPORT_PATH}` are shared by design: +they are the household's own folders, which every media app reads. **Pinned by** `internal/privpolicy/privpolicy_test.go` (each class refused, with positive controls), `stacks.TestAllowList_IsWiredIntoEveryComposeWriter` (AST: every compose writer and every env decision point asks diff --git a/documentation/architecture/03-host-agent.md b/documentation/architecture/03-host-agent.md index 7bdcdd08..e76aa907 100644 --- a/documentation/architecture/03-host-agent.md +++ b/documentation/architecture/03-host-agent.md @@ -113,7 +113,7 @@ fixed file, delivered by the signed config bundle): | `FELHOM_CONTROLLERSWAP` | the managed controller update | exact vmid; image ref pinned to `gitea.dooplex.hu/admin/felhom-controller:X.Y.Z` for the image check; the inspect template stays free text; **the write goes through `felhom-priv-apply controller-image `** (the ref on stdin, re-checked as root against the same pattern — R-861 (a) A1, `09` §3 decision 165, agent after v0.150.0) | guest-scoped: a compromised agent can restart the guest's bootstrap and choose an OLDER version of OUR controller image (a downgrade); it can no longer hand the guest any other image. Until the A1 bundle reached a box, the agent's in-guest `tee` let it write any ref (sudo cannot see stdin — the 2026-10-06 night correction, `audits/night-burndown-2026-10-06/design-R-861.md`) | | `FELHOM_STALELOCK` / `FELHOM_SCRATCH_TEARDOWN` | stale-lock clear; failed restore-test scratch | exact vmid; the scratch band `99000[0-9]` was already exact | — | | `FELHOM_VZPARTIAL` | remove a dead half-written vzdump (R-1006, agent v0.156.1) | ONE line: `felhom-vzdump-partial-clean `; the root helper (a config-bundle file) re-checks: a `dir` storage from `storage.cfg`, the name of that vmid (`.tar.dat`, `.vma.dat`, `.tmp`), not a symlink, directly in `/dump`, no vzdump on the host, nothing holds it open, dead (before this boot or quiet 120 s) | a compromised agent can delete a dead partial — never a finished archive, never a live one | -| `FELHOM_THINCHECK` | name an ORPHAN thin device around a whole-guest backup (R-1012, agent v0.159.0) | ONE line: `felhom-thin-check `; the root helper (a config-bundle file) lists LVM's thin ids before and after and the pool's ids through a metadata snapshot it reserves and releases; it refuses (exit 3) when someone else holds a metadata snapshot and sends no other pool message. The agent reports an id in the pool and in neither LVM list (two reads) in the backup failure's text; the repair (`runbooks/whole-guest-backup-orphan-thin.md`) stays human | a compromised agent can READ the pool's device ids — it cannot delete, create or change a thin device | +| `FELHOM_THINCHECK` | name an ORPHAN thin device when a whole-guest backup has failed (R-1012, agent v0.159.0) | ONE line: `felhom-thin-check `; the root helper (a config-bundle file) lists LVM's thin ids before and after and the pool's ids through a metadata snapshot it reserves and releases; it refuses (exit 3) when someone else holds a metadata snapshot and sends no other pool message. The agent runs it ONLY when a snapshot-mode vzdump has failed (start or task) — the moment the answer is needed; a successful backup never takes the pool's metadata snapshot (v0.159.0/v0.159.1 also ran it before every snapshot backup; the next agent release after v0.159.1 drops that pre-run check). It reports an id in the pool and in neither LVM list (two reads) in the backup failure's text; the repair (`runbooks/whole-guest-backup-orphan-thin.md`) stays human | a compromised agent can READ the pool's device ids — it cannot delete, create or change a thin device | | `FELHOM_MOUNT` `unit-forget` | forget a decommissioned drive that is gone (R-1124, agent v0.159.0) | `felhom-priv-apply unit-forget mnt-<…>.mount` removes ONE unit file, only a felhom by-UUID drive unit (not a network unit) that is disabled, not mounted, and whose `/dev/disk/by-uuid` link is absent; the agent calls it at start and on the 20-s tick for drives whose intent is `decommissioned` | a compromised agent can delete the unit of an ABSENT, unmounted drive — the same effect as unplugging it; a present drive keeps its unit | | `FELHOM_WG` | the off-site tunnel | conf via `felhom-priv-apply wg` (only the keys `renderConf` writes; no `PostUp`/`PreUp`/`DNS`/`Table`; `/32` only) | — | | `FELHOM_SELFUPDATE` | commit / rollback of the A/B flip | **`apply` removed**: the flip runs only inside `felhom-os-apply agent_update`, after the operator signature, host, window and nonce are checked as root and the staged bytes are hashed ONCE and copied to a root-owned dir (`/var/lib/felhom-os-apply/agent-update/`); the wrapper accepts only that dir | — | diff --git a/documentation/architecture/05-hub-architecture.md b/documentation/architecture/05-hub-architecture.md index 897bd142..16c84398 100644 --- a/documentation/architecture/05-hub-architecture.md +++ b/documentation/architecture/05-hub-architecture.md @@ -132,7 +132,9 @@ touches WAF. the floor carries it to every box (MinAgent declared), raised after the release ran on the three test boxes and the box walk is green; the golden is baked weekly and vouched by the operator; a new box installs the vouched golden and updates itself to the floor (R-1052: not yet proven end to end). Setting the global floor today needs the operator page with the -operator's password — there is no scoped route for CC (R-1051). +operator's password — there is no scoped route for CC (R-1051). **An agent can be vouched mid-week; the golden stays +weekly** (hub v0.158.0): the R-120 golden guard judges only a CHANGED golden selection, so a Day-0 save that keeps the +vouched golden (same version and sha) saves a new agent even while that golden is behind the fleet. **The controller floor and its agent requirement (hub v0.112.0, R-472).** The managed controller floor rides the report ACK. `store.ResolveManagedFloor` decides per box whether to serve it, from three @@ -505,6 +507,21 @@ namespace (`runbooks/RUNBOOK-hub-db-offsite-backup.md`). Pinned by `internal/dbs `cmd/hub/r173_wiring_test.go`. +### 16.4 The hub's own access log [DESIGN — hub v0.158.0, operator decision A on R-1140, 2026-10-17 22:26] + +**Why:** R-954 asked „did anyone use the old hub key before 2026-10-12?" and nobody could answer — the ingress +controller's container log covers about half a day (k3s keeps 10 MiB × 5) and the hub logged no requests. **What is +kept:** one line per request the hub serves — time (UTC), method, the PATH (the query string is dropped; the self-bind +capability in `/bind/` and any path segment of 32+ characters are written as `[redacted]`), status, duration, +the socket peer, the X-Forwarded-For hops that parse as IP addresses (recorded, never trusted), the KIND of credential +presented and the identity kind the hub's auth established (customer, host, global, session, basic, token) — never a +key, token, password, cookie or passphrase value (`TestAccessLog_NeverWritesASecret`). kube-probe's own `/healthz` +is not logged. **Where and how long:** `/access-log/access-YYYY-MM-DD.log` on the hub's own volume (`/data`, +the `hub-data` PVC; no new env var, no manifest change), one file per UTC day, mode 0600; files older than **90 days** +are deleted at start-up and at each new day (`TestAccessLog_Keeps90DaysThenDeletes`). Measured 2026-10-17 from the +ingress log: ≈ 1,900 hub requests a day at ≈ 110 bytes a line → ≈ 0.2 MB a day, ≈ 19 MB for 90 days. A logging +failure never fails or delays a request: lines go through a non-blocking buffer to one writer (`internal/accesslog`). + ## 17. Operator access tokens [DESIGN — hub v0.152.0, operator ruling 2026-10-15 11:38 (`09` §3 decision 251)] **The problem.** Scripts — Claude Code's floor step first — drove the hub with the operator's own password (HTTP Basic, diff --git a/documentation/architecture/09-update-architecture.md b/documentation/architecture/09-update-architecture.md index dce5b69e..8d59e012 100644 --- a/documentation/architecture/09-update-architecture.md +++ b/documentation/architecture/09-update-architecture.md @@ -969,9 +969,13 @@ its length, and both fixes cost something the household would notice — operato *Route:* the floor save on the operator page, with CC's scoped token (decision 251, `05` §17); until the token works live, the operator password for the floor only (R-1051). 3. **Agent releases (and their bundles) still stop for the operator's vouch;** a floor whose MinAgent is above the - vouched agent is never set. + vouched agent is never set. **An agent can be vouched mid-week:** a Day-0 save that leaves the golden as vouched + (same version and sha) is not refused by the R-120 golden guard even while the golden is behind the fleet (hub + v0.158.0, `TestVouchAgentOnlyWithStaleGoldenIsSaved`). 4. **The golden is baked weekly** (Sunday night, `runbooks/nightly-rotation.md`); the operator vouches it. A new box - installs the vouched golden and updates itself to the floor (not yet proven end to end — R-1052). + installs the vouched golden and updates itself to the floor (not yet proven end to end — R-1052). **The golden + stays weekly:** a CHANGED golden selection is still refused when it is older than the fleet's newest controller + (`TestVouchGoldenChangedToOlderIsStillRefused`). 5. The push gate judges the golden by its AGE (older than 7 days while the floor is above it), not by the newest CHANGELOG heading (`scripts/golden_currency_gate.py`). 251. **Scripts use scoped hub tokens, not the operator password; CC's floor step uses its own.** *Operator ruling diff --git a/documentation/runbooks/break-glass.md b/documentation/runbooks/break-glass.md index b77698bf..a2a89f42 100644 --- a/documentation/runbooks/break-glass.md +++ b/documentation/runbooks/break-glass.md @@ -86,16 +86,25 @@ Fix the cause; the three layers are the safety net, not the cure. - **Keep the build-server PVE token fresh.** In the spike incident the build-server-cached PVE token (`kisfenyo@192.168.0.180:~/felhom-agent-demo.json`) was **stale (401)** and left no non-SSH lever before the web-console path was used. A working break-glass path independent of sshd must always exist. -- **Rotate the console credential** with `felhom-host-install … --rotate-recovery` (regenerates + - re-vaults; a plain re-run does NOT rotate, to avoid stranding your saved copy). Full auto-rotation is - a future item. +- **Rotate the console credential ALONE** with `sudo bash felhom-host-install.sh --rotate-recovery-only` + (R-1141; try it first with `--dry-run`). It runs step 4b and nothing else: a new random `root@pam` + password, set with `chpasswd` and re-vaulted to the hub with the host key from the agent's own config + (`/etc/felhom-agent/agent.json`). It does NOT reinstall or change the agent, its config or the root + files, needs no passphrase or customer id, checks that the hub answers (`/healthz` 200) before the + password changes, and refuses a byo host (also an agent config whose `deployment_mode` is not + `appliance`). Proof after a rotation: the new vaulted value gets a PVE ticket (200), the old one + gets 401. The flag ships with the first `installer-v…` tag after installer 1.33.0 — until then the + served installer does not know it. The older `--rotate-recovery` flag only works inside a FULL + installer re-run, which also reinstalls the vouched agent and the root files (on a box ahead of the + vouched agent it moves the agent back) — do not use it for a password change. A plain re-run does NOT + rotate, to avoid stranding your saved copy. Full auto-rotation is a future item. - **Operator-set FIXED credential (e.g. demo-felhom-01, pinned 2026-07-12).** A host's `root@pam` may be deliberately set to a *known operator-chosen* password instead of the random day-0 one. Do it the same way step 4b does, just with your password: set it on the box (`printf 'root:\n' | chpasswd`), then re-vault with `PUT /api/v1/hosts//recovery-credential` (host `api_key` from `/etc/felhom-agent/agent.json`; expect HTTP 200), and ensure `break_glass` is in `/var/lib/felhom-install/state.json`'s `completed[]`. This **survives plain installer re-runs** - (step 4b skips on the marker). Two caveats: (a) **never `--rotate-recovery` such a host** — it + (step 4b skips on the marker). Two caveats: (a) **never `--rotate-recovery` or `--rotate-recovery-only` such a host** — it replaces your known copy with a random one; (b) a **full from-scratch reinstall** (uninstall→install) wipes `state.json`, so step 4b re-randomizes — re-run the set-and-vault afterward. Background: on each full reinstall this is exactly why `root@pam` "kept changing" until it was pinned. diff --git a/hub/CHANGELOG.md b/hub/CHANGELOG.md index 94d80fb9..ee04380c 100644 --- a/hub/CHANGELOG.md +++ b/hub/CHANGELOG.md @@ -1,3 +1,32 @@ +## v0.158.0 — agent-only vouch, the hub's own snapshot alarms, the hub's own access log (2026-10-17) — built, NOT deployed (decision 162 — night) + +- **An agent can be vouched mid-week** (`09` §3 decision 250 items 3–4). The Day-0 save's R-120 golden guard refused + EVERY save while the weekly golden was behind the fleet — an agent-only vouch included. It now judges only a CHANGED + golden selection: a save that keeps the vouched golden (same version AND same sha256) is saved; a golden changed to an + older one, or the same version under another sha, is refused as before. The MinAgent rule for a floor is untouched. + Pinned by `TestVouchAgentOnlyWithStaleGoldenIsSaved` (red-proved: without the condition it fails with + `flash=golden_behind_fleet`) and `TestVouchGoldenChangedToOlderIsStillRefused`. +- **R-895 slice 2 — the alarms on the hub's own snapshot listing.** The 07:10 key audit now compares the box's restic + `snapshots/` listing with yesterday's, by name: files gone that no hub-opened clean-up window explains → + `offsite_snapshots_vanished` (error); files uploaded when the box reported no off-site run (`offsite.last_run` in its + reports, ± 3 h for the provider shell's unmeasured time zone, a run counted as the 6 h before its end) → + `offsite_snapshots_unexplained` (warning). Both operator-only (`operatorOnlyEvents`), hub-origin only (NOT in + `allowedEventTypes`, so no box can post one). No new credential (the same sealed sub-account login, one `ls -l`). + False-alarm guards: the first listing is a baseline; a move-aside or a RESET purge drops the baseline; vanishing is + judged only on a pinned tier; a file younger than 1 h is judged the next day; the log line now also prints the box's + last reported run beside the newest upload time (the time-zone calibration). Not built: the window's before/after on + the hub's count and refusing a window while unexplained files exist. `internal/offsitekeys/snapshot_watch.go`, + baseline in `hub_settings` (`store/offsite_snapshots.go`); red-proved (`snapshot_watch_test.go`). +- **The hub's own access log, 90 days** (R-1140, operator decision A 2026-10-17 22:26; `05` §16.4). One line per request + — time, method, PATH (no query; `/bind/` and any 32+-character segment redacted), status, duration, socket + peer, the X-Forwarded-For hops that are IP addresses, the credential KIND presented and the identity kind the hub's + auth established — never a value. `/data/access-log/access-YYYY-MM-DD.log` (the existing PVC, no manifest change), + 0600, deleted after 90 days; kube-probe's `/healthz` is skipped. A non-blocking buffer and one writer: a logging + failure never fails or delays a request. Expected ≈ 0.2 MB a day, ≈ 19 MB for 90 days (measured: ≈ 1,900 hub + requests a day through the ingress). Pinned by `TestAccessLog_NeverWritesASecret` (red-proved with the raw URL: + `[bind query segment]` leaked), `TestAccessLog_Keeps90DaysThenDeletes` (injected clock), + `TestAccessLog_APIMarksTheIdentityKindNeverTheKey`, `TestServerHandlerIsAccessLogged` (main wires it). + ## v0.157.0 — the allow-list's operator event, the vault time moves on a re-vault, the hub's own snapshot count (2026-10-17) - **`app_definition_refused`** (R-971, operator decision D2 = A): controller v0.328.0 refuses, before it writes any app diff --git a/hub/cmd/hub/main.go b/hub/cmd/hub/main.go index 9f6b6f7d..196845b3 100644 --- a/hub/cmd/hub/main.go +++ b/hub/cmd/hub/main.go @@ -14,6 +14,7 @@ import ( "syscall" "time" + "gitea.dooplex.hu/admin/felhom-hub/internal/accesslog" "gitea.dooplex.hu/admin/felhom-hub/internal/api" "gitea.dooplex.hu/admin/felhom-hub/internal/assets" "gitea.dooplex.hu/admin/felhom-hub/internal/claim" @@ -678,10 +679,16 @@ func main() { } mux.Handle("/", webServer.Handler()) + // R-1140 (operator decision A, 2026-10-17): the hub's OWN access log — one line per request, a file per UTC day under + // /access-log on the hub's volume, kept 90 days. Path only (no query), no credential value; a logging + // failure never fails or delays a request (internal/accesslog). Pinned by TestServerHandlerIsAccessLogged. + accessLog := accesslog.New(accesslog.Options{Dir: filepath.Join(cfg.Server.DataDir, "access-log"), Logf: logger.Printf}) + logger.Printf("[INFO] access log: %s, one file per UTC day, kept %d days", filepath.Join(cfg.Server.DataDir, "access-log"), int(accesslog.DefaultKeep.Hours()/24)) + // Start HTTP server server := &http.Server{ Addr: cfg.Server.Listen, - Handler: mux, + Handler: accessLog.Middleware(mux), ReadTimeout: 30 * time.Second, WriteTimeout: 60 * time.Second, IdleTimeout: 120 * time.Second, @@ -979,6 +986,7 @@ func main() { logger.Fatalf("[FATAL] HTTP server error: %v", err) } + accessLog.Close() // drains the buffered lines of the last requests logger.Println("[INFO] felhom-hub stopped") } diff --git a/hub/cmd/hub/r1140_wiring_test.go b/hub/cmd/hub/r1140_wiring_test.go new file mode 100644 index 00000000..3a71f5df --- /dev/null +++ b/hub/cmd/hub/r1140_wiring_test.go @@ -0,0 +1,53 @@ +package main + +import ( + "go/ast" + "go/parser" + "go/token" + "testing" +) + +// TestServerHandlerIsAccessLogged (R-1140, hub v0.158.0): the http.Server's Handler is the access log's Middleware +// around the mux — so EVERY route (API, operator UI, /bind/, /healthz) passes it. A log package nobody mounts is the +// seam-built-never-wired class (REUSE.md trap). RED-PROOF: `Handler: mux,` → FAIL. +func TestServerHandlerIsAccessLogged(t *testing.T) { + f, err := parser.ParseFile(token.NewFileSet(), "main.go", nil, 0) + if err != nil { + t.Fatal(err) + } + var wrapped, servers int + ast.Inspect(f, func(n ast.Node) bool { + cl, ok := n.(*ast.CompositeLit) + if !ok { + return true + } + sel, ok := cl.Type.(*ast.SelectorExpr) + if !ok || sel.Sel.Name != "Server" { + return true + } + if x, ok := sel.X.(*ast.Ident); !ok || x.Name != "http" { + return true + } + servers++ + for _, el := range cl.Elts { + kv, ok := el.(*ast.KeyValueExpr) + if !ok { + continue + } + if k, ok := kv.Key.(*ast.Ident); !ok || k.Name != "Handler" { + continue + } + if call, ok := kv.Value.(*ast.CallExpr); ok { + if s, ok := call.Fun.(*ast.SelectorExpr); ok && s.Sel.Name == "Middleware" && len(call.Args) == 1 { + if a, ok := call.Args[0].(*ast.Ident); ok && a.Name == "mux" { + wrapped++ + } + } + } + } + return true + }) + if servers != 1 || wrapped != 1 { + t.Fatalf("http.Server literals: %d, with Handler: accessLog.Middleware(mux): %d — want 1 and 1", servers, wrapped) + } +} diff --git a/hub/internal/accesslog/accesslog.go b/hub/internal/accesslog/accesslog.go new file mode 100644 index 00000000..6144cb85 --- /dev/null +++ b/hub/internal/accesslog/accesslog.go @@ -0,0 +1,396 @@ +// Package accesslog is the hub's OWN access log (R-1140, operator decision A 2026-10-17 22:26: „a separate log for the +// hub only"; `05` §16.4). One line per request the hub serves, in a file per UTC day on the hub's own volume +// (`/access-log/access-YYYY-MM-DD.log`), kept 90 days and then deleted. +// +// WHY: R-954 asked „did anyone use the old hub key before 2026-10-12?" and could not be answered — the ingress +// controller's container log covers about half a day (k3s rotates it at 10 MiB × 5), and the hub logged no requests. +// +// WHAT A LINE HOLDS — and what it never holds. Example: +// +// 2026-10-17T20:35:16Z POST /api/v1/report 200 12ms remote=10.42.0.31 xff=192.168.0.149 cred=bearer auth=customer +// +// The PATH only: the query string is dropped entirely (it can carry a token), and a path segment that is a capability +// (`/bind/`) or any segment of 32+ characters is written as `[redacted]` (TestAccessLog_NeverWritesASecret). +// remote is the socket peer (behind ingress-nginx: the ingress pod); xff is the X-Forwarded-For header as the hub +// received it, each hop kept only if it parses as an IP address (anything else is written as `?`). Neither is trusted +// for anything; both are recorded so the reader can judge. cred is the KIND of credential presented (bearer, token, +// basic, session-cookie, passphrase), read from header names and prefixes — never a value. auth is the identity the +// hub's own auth helpers ESTABLISHED (customer, host, global, session, basic, token), set through Mark; `-` when none +// did (a public route, a refusal, or a handler's own check). +// +// A LOGGING FAILURE NEVER FAILS OR DELAYS A REQUEST. The middleware hands the line to a buffered channel without +// blocking; a single writer goroutine does every file operation. A full buffer drops the line and counts it; an +// unwritable directory is reported (rate-limited) and the request is served as before. +// +// kube-probe's own /healthz requests (no X-Forwarded-For, User-Agent kube-probe/…) are not logged: 11,520 lines a day +// that say nothing, and they would be 85 % of the file. A /healthz that came through the ingress is logged. +package accesslog + +import ( + "context" + "fmt" + "net" + "net/http" + "os" + "path/filepath" + "regexp" + "sort" + "strings" + "sync" + "time" +) + +// DefaultKeep is how long a day's file is kept (operator decision A on R-1140: 90 days). +const DefaultKeep = 90 * 24 * time.Hour + +const bufferLines = 2048 + +var fileRe = regexp.MustCompile(`^access-(\d{4}-\d{2}-\d{2})\.log$`) + +// Log is the hub's access log. Zero values are not usable; build it with New. +type Log struct { + dir string + keep time.Duration + now func() time.Time + logf func(format string, a ...any) + + ch chan string + done chan struct{} + + // writer-goroutine state (touched only by run) + f *os.File + day string + lastPrune string + lastErrAt time.Time + + mu sync.Mutex + dropped int64 + closed bool +} + +// Options configure New. Now and Logf are seams for tests; nil → time.Now / discard. Logf receives the access log's +// own operational lines (a rate-limited write failure, a prune) — never a request line. +type Options struct { + Dir string + Keep time.Duration + Now func() time.Time + Logf func(format string, a ...any) +} + +// New starts the writer and prunes once. The directory is created on first write, never at construction, so a +// missing volume costs a logged error and nothing else. +func New(o Options) *Log { + l := &Log{dir: o.Dir, keep: o.Keep, now: o.Now, logf: o.Logf, + ch: make(chan string, bufferLines), done: make(chan struct{})} + if l.keep <= 0 { + l.keep = DefaultKeep + } + if l.now == nil { + l.now = time.Now + } + if l.logf == nil { + l.logf = func(string, ...any) {} + } + go l.run() + return l +} + +// Close drains the buffer, closes the file and stops the writer. Safe to call twice. +func (l *Log) Close() { + l.mu.Lock() + if l.closed { + l.mu.Unlock() + return + } + l.closed = true + close(l.ch) + l.mu.Unlock() + <-l.done +} + +// Dropped is how many lines a full buffer (or a closed log) refused. +func (l *Log) Dropped() int64 { + l.mu.Lock() + defer l.mu.Unlock() + return l.dropped +} + +func (l *Log) enqueue(line string) { + l.mu.Lock() + defer l.mu.Unlock() + if l.closed { + l.dropped++ + return + } + select { + case l.ch <- line: + default: + l.dropped++ + } +} + +func (l *Log) run() { + defer close(l.done) + l.prune() + for line := range l.ch { + l.write(line) + } + if l.f != nil { + _ = l.f.Close() + } +} + +func (l *Log) fail(what string, err error) { + // One report a minute at most: a full or missing volume must not flood the hub's own log. + if now := l.now(); now.Sub(l.lastErrAt) >= time.Minute { + l.lastErrAt = now + l.logf("[WARN] access log: %s: %v (the request was served; this line is lost)", what, err) + } +} + +func (l *Log) write(line string) { + day := l.now().UTC().Format("2006-01-02") + if l.f == nil || day != l.day { + if l.f != nil { + _ = l.f.Close() + l.f = nil + } + if err := os.MkdirAll(l.dir, 0o700); err != nil { + l.fail("create "+l.dir, err) + return + } + f, err := os.OpenFile(filepath.Join(l.dir, "access-"+day+".log"), os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o600) + if err != nil { + l.fail("open the day's file", err) + return + } + l.f, l.day = f, day + if day != l.lastPrune { + l.prune() + } + } + if _, err := l.f.WriteString(line); err != nil { + l.fail("write", err) + } +} + +// prune deletes day files older than keep. Only names of the exact form access-YYYY-MM-DD.log are ever removed. +func (l *Log) prune() { + now := l.now().UTC() + l.lastPrune = now.Format("2006-01-02") + cutoff := now.Add(-l.keep).Format("2006-01-02") + ents, err := os.ReadDir(l.dir) + if err != nil { + if !os.IsNotExist(err) { + l.fail("read "+l.dir, err) + } + return + } + var removed []string + for _, e := range ents { + m := fileRe.FindStringSubmatch(e.Name()) + if m == nil || e.IsDir() { + continue + } + if _, perr := time.Parse("2006-01-02", m[1]); perr != nil { + continue + } + if m[1] < cutoff { + if err := os.Remove(filepath.Join(l.dir, e.Name())); err != nil { + l.fail("remove "+e.Name(), err) + continue + } + removed = append(removed, e.Name()) + } + } + if len(removed) > 0 { + sort.Strings(removed) + l.logf("[INFO] access log: removed %d day file(s) older than %d days: %s", len(removed), int(l.keep.Hours()/24), strings.Join(removed, ", ")) + } +} + +// ── identity marks ────────────────────────────────────────────────────────────────────────────────── + +type ctxKey struct{} + +type entry struct { + mu sync.Mutex + auth string +} + +// Mark records the identity kind an auth helper established for this request ("customer", "host", "global", +// "session", "basic", "token"). A KIND only — never a name, a key or a token. No-op outside the middleware. +func Mark(ctx context.Context, kind string) { + if e, ok := ctx.Value(ctxKey{}).(*entry); ok { + e.mu.Lock() + e.auth = kind + e.mu.Unlock() + } +} + +// ── the middleware ────────────────────────────────────────────────────────────────────────────────── + +type recorder struct { + http.ResponseWriter + status int +} + +func (r *recorder) WriteHeader(code int) { + if r.status == 0 { + r.status = code + } + r.ResponseWriter.WriteHeader(code) +} + +func (r *recorder) Write(b []byte) (int, error) { + if r.status == 0 { + r.status = http.StatusOK + } + return r.ResponseWriter.Write(b) +} + +// Flush and Unwrap keep http.ResponseController (the /api/v1/wait long-poll's Flush and SetWriteDeadline) working. +func (r *recorder) Flush() { + if f, ok := r.ResponseWriter.(http.Flusher); ok { + f.Flush() + } +} + +func (r *recorder) Unwrap() http.ResponseWriter { return r.ResponseWriter } + +// Middleware logs every request next serves. nil l → next unchanged. +func (l *Log) Middleware(next http.Handler) http.Handler { + if l == nil { + return next + } + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + if r.URL.Path == "/healthz" && r.Header.Get("X-Forwarded-For") == "" && strings.HasPrefix(r.UserAgent(), "kube-probe/") { + next.ServeHTTP(w, r) + return + } + start := l.now() + e := &entry{} + rec := &recorder{ResponseWriter: w} + finished := false + defer func() { + status := fmt.Sprint(rec.status) + if !finished { + status = "panic" + } else if rec.status == 0 { + status = "200" + } + e.mu.Lock() + auth := e.auth + e.mu.Unlock() + l.enqueue(FormatLine(start, r, status, l.now().Sub(start), auth)) + }() + next.ServeHTTP(rec, r.WithContext(context.WithValue(r.Context(), ctxKey{}, e))) + finished = true + }) +} + +// FormatLine renders one line. Exported for the size measurement and the tests; it reads only the method, the PATH, +// the socket peer, X-Forwarded-For (IPs only) and the NAMES/prefixes of the credential headers. +func FormatLine(start time.Time, r *http.Request, status string, dur time.Duration, auth string) string { + if auth == "" { + auth = "-" + } + remote := r.RemoteAddr + if h, _, err := net.SplitHostPort(remote); err == nil { + remote = h + } + return fmt.Sprintf("%s %s %s %s %dms remote=%s xff=%s cred=%s auth=%s\n", + start.UTC().Format("2006-01-02T15:04:05Z"), safeToken(r.Method, 10), SafePath(r), status, + dur.Milliseconds(), safeIP(remote), safeXFF(r.Header.Get("X-Forwarded-For")), credKind(r), auth) +} + +// SafePath is the request path with no query string, escaped (no space or newline can reach the file), with capability +// segments redacted, at most 256 bytes. +func SafePath(r *http.Request) string { + p := r.URL.EscapedPath() + if p == "" { + p = "/" + } + segs := strings.Split(p, "/") + for i, s := range segs { + switch { + case i > 0 && segs[i-1] == "bind" && i == 2: // /bind/[/resend] — the self-bind capability + segs[i] = "[redacted]" + case len(s) >= 32: + segs[i] = "[redacted]" + } + } + p = strings.Join(segs, "/") + if len(p) > 256 { + p = p[:256] + "…" + } + return p +} + +func safeToken(s string, max int) string { + var b strings.Builder + for _, c := range s { + if c >= 'A' && c <= 'Z' || c >= 'a' && c <= 'z' { + b.WriteRune(c) + } + } + if b.Len() == 0 || b.Len() > max { + return "?" + } + return b.String() +} + +func safeIP(s string) string { + if ip := net.ParseIP(strings.TrimSpace(s)); ip != nil { + return ip.String() + } + if s == "" { + return "-" + } + return "?" +} + +func safeXFF(h string) string { + if strings.TrimSpace(h) == "" { + return "-" + } + var hops []string + for i, part := range strings.Split(h, ",") { + if i == 8 { + hops = append(hops, "…") + break + } + hops = append(hops, safeIP(part)) + } + return strings.Join(hops, ",") +} + +// credKind names the credential presented — never its value. +func credKind(r *http.Request) string { + var kinds []string + if a := r.Header.Get("Authorization"); a != "" { + switch { + case strings.HasPrefix(a, "Bearer fhp_"): + kinds = append(kinds, "token") + case strings.HasPrefix(a, "Bearer "): + kinds = append(kinds, "bearer") + case strings.HasPrefix(a, "Basic "): + kinds = append(kinds, "basic") + default: + kinds = append(kinds, "other") + } + } + for _, c := range r.Cookies() { + if strings.HasSuffix(c.Name, "hub_session") { + kinds = append(kinds, "session-cookie") + break + } + } + if r.Header.Get("X-Retrieval-Password") != "" { + kinds = append(kinds, "passphrase") + } + if len(kinds) == 0 { + return "-" + } + return strings.Join(kinds, "+") +} diff --git a/hub/internal/accesslog/accesslog_test.go b/hub/internal/accesslog/accesslog_test.go new file mode 100644 index 00000000..50efd381 --- /dev/null +++ b/hub/internal/accesslog/accesslog_test.go @@ -0,0 +1,235 @@ +package accesslog + +import ( + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "sort" + "strings" + "sync" + "testing" + "time" +) + +type clock struct { + mu sync.Mutex + t time.Time +} + +func (c *clock) now() time.Time { c.mu.Lock(); defer c.mu.Unlock(); return c.t } +func (c *clock) set(t time.Time) { c.mu.Lock(); c.t = t; c.mu.Unlock() } + +func readAll(t *testing.T, dir string) string { + t.Helper() + ents, _ := os.ReadDir(dir) + var b strings.Builder + for _, e := range ents { + raw, err := os.ReadFile(filepath.Join(dir, e.Name())) + if err != nil { + t.Fatal(err) + } + b.Write(raw) + } + return b.String() +} + +func serve(h http.Handler, r *http.Request) *httptest.ResponseRecorder { + w := httptest.NewRecorder() + h.ServeHTTP(w, r) + return w +} + +// A request is logged: one line, in today's file, with method, path, status, the socket peer, the forwarded-for hop and +// the identity kind the handler's auth helper marked. +func TestAccessLog_ARequestIsLogged(t *testing.T) { + dir := t.TempDir() + c := &clock{t: time.Date(2026, 10, 17, 20, 35, 16, 0, time.UTC)} + l := New(Options{Dir: dir, Now: c.now}) + h := l.Middleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + Mark(r.Context(), "customer") + w.WriteHeader(http.StatusAccepted) + })) + r := httptest.NewRequest(http.MethodPost, "/api/v1/report", nil) + r.RemoteAddr = "10.42.0.31:51234" + r.Header.Set("X-Forwarded-For", "192.168.0.149") + r.Header.Set("Authorization", "Bearer 0123") + if w := serve(h, r); w.Code != http.StatusAccepted { + t.Fatalf("status %d", w.Code) + } + l.Close() + raw, err := os.ReadFile(filepath.Join(dir, "access-2026-10-17.log")) + if err != nil { + t.Fatalf("today's file: %v", err) + } + want := "2026-10-17T20:35:16Z POST /api/v1/report 202 0ms remote=10.42.0.31 xff=192.168.0.149 cred=bearer auth=customer\n" + if string(raw) != want { + t.Fatalf("line =\n%q\nwant\n%q", raw, want) + } + if fi, _ := os.Stat(filepath.Join(dir, "access-2026-10-17.log")); fi.Mode().Perm() != 0o600 { + t.Fatalf("file mode %v, want 0600", fi.Mode().Perm()) + } +} + +// NO SECRET REACHES THE FILE: a bearer token, an operator access token, Basic credentials, a session cookie, a +// retrieval passphrase, a token in the query string, a self-bind capability in the path, a long secret-shaped path +// segment, and a secret stuffed into X-Forwarded-For. Positive control: the same line's path and method ARE there. +// RED-PROOF (2026-10-17 night): with SafePath returning r.URL.RequestURI() (the raw URL), this fails with +// `secrets written to the access log: [bind query segment]`. +func TestAccessLog_NeverWritesASecret(t *testing.T) { + secrets := map[string]string{ + "bearer": "4f1c9e2b7a60d38e5b9c0a1f2e3d4c5b6a7980f1e2d3c4b5a69788f0e1d2c3b4", + "fhp": "fhp_abcdefghijklmnopqrstuvwxyz234567abcdefghijklmnopqrst", + "basic": "operator-password-Xy9", + "cookie": "c0ffee0123456789c0ffee0123456789c0ffee0123456789c0ffee0123456789", + "passphrase": "korte-alma-szilva-barack", + "query": "QUERYTOKEN-5d2a9f", + "bind": "BINDTOKEN-77aa88bb99cc", + "segment": "Zm9vYmFyYmF6cXV4cXV1eHF1dXhxdXV4cXV1eA", + "xff": "XFFSECRET-123", + } + dir := t.TempDir() + l := New(Options{Dir: dir}) + h := l.Middleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {})) + reqs := []*http.Request{ + httptest.NewRequest(http.MethodGet, "/api/v1/wait?gen=4&token="+secrets["query"], nil), + httptest.NewRequest(http.MethodGet, "/bind/"+secrets["bind"], nil), + httptest.NewRequest(http.MethodPost, "/bind/"+secrets["bind"]+"/resend", nil), + httptest.NewRequest(http.MethodGet, "/api/v1/assets/file/"+secrets["segment"], nil), + httptest.NewRequest(http.MethodGet, "/configuration", nil), + } + reqs[0].Header.Set("Authorization", "Bearer "+secrets["bearer"]) + reqs[1].Header.Set("Authorization", "Bearer "+secrets["fhp"]) + reqs[2].SetBasicAuth("operator", secrets["basic"]) + reqs[3].AddCookie(&http.Cookie{Name: "__Host-hub_session", Value: secrets["cookie"]}) + reqs[4].Header.Set("X-Retrieval-Password", secrets["passphrase"]) + reqs[4].Header.Set("X-Forwarded-For", secrets["xff"]+", 192.168.0.149") + for _, r := range reqs { + serve(h, r) + } + l.Close() + got := readAll(t, dir) + var leaked []string + for name, v := range secrets { + if strings.Contains(got, v) { + leaked = append(leaked, name) + } + } + sort.Strings(leaked) + if len(leaked) > 0 { + t.Fatalf("secrets written to the access log: %v\n%s", leaked, got) + } + for _, want := range []string{"GET /api/v1/wait 200", "GET /bind/[redacted] 200", "POST /bind/[redacted]/resend", + "/api/v1/assets/file/[redacted]", "cred=token", "cred=basic", "cred=session-cookie", "cred=passphrase", "xff=?,192.168.0.149"} { + if !strings.Contains(got, want) { + t.Errorf("positive control missing %q in\n%s", want, got) + } + } + if n := strings.Count(got, "\n"); n != len(reqs) { + t.Errorf("%d line(s), want %d", n, len(reqs)) + } +} + +// Day files older than 90 days are removed — at start and at each new day — and nothing else in the directory is. +func TestAccessLog_Keeps90DaysThenDeletes(t *testing.T) { + dir := t.TempDir() + for _, n := range []string{"access-2026-07-18.log", "access-2026-07-19.log", "access-2026-10-16.log", "notes.txt", "access-2026-07-01.log.keep"} { + if err := os.WriteFile(filepath.Join(dir, n), []byte("x\n"), 0o600); err != nil { + t.Fatal(err) + } + } + c := &clock{t: time.Date(2026, 10, 17, 1, 0, 0, 0, time.UTC)} + l := New(Options{Dir: dir, Now: c.now}) + h := l.Middleware(http.HandlerFunc(func(http.ResponseWriter, *http.Request) {})) + serve(h, httptest.NewRequest(http.MethodGet, "/", nil)) + // The next day: the first line of 2026-10-18 opens a new file and prunes again (2026-07-19 is now 91 days old). + // Let the writer take the first line on 10-17 before the clock moves (poll the file, never a bare sleep). + for i := 0; ; i++ { + if _, err := os.Stat(filepath.Join(dir, "access-2026-10-17.log")); err == nil { + break + } + if i == 200 { + t.Fatal("the 10-17 line was never written") + } + time.Sleep(10 * time.Millisecond) + } + c.set(time.Date(2026, 10, 18, 0, 0, 5, 0, time.UTC)) + serve(h, httptest.NewRequest(http.MethodGet, "/", nil)) + l.Close() + var names []string + ents, _ := os.ReadDir(dir) + for _, e := range ents { + names = append(names, e.Name()) + } + sort.Strings(names) + want := []string{"access-2026-07-01.log.keep", "access-2026-10-16.log", "access-2026-10-17.log", "access-2026-10-18.log", "notes.txt"} + if strings.Join(names, " ") != strings.Join(want, " ") { + t.Fatalf("files = %v\nwant %v", names, want) + } +} + +// A logging failure never fails the request: the directory cannot be created, the handler's answer is unchanged, and +// the failure is reported (once a minute at most) to the hub's own log. +func TestAccessLog_FailureNeverFailsTheRequest(t *testing.T) { + blocker := filepath.Join(t.TempDir(), "file-not-dir") + if err := os.WriteFile(blocker, nil, 0o600); err != nil { + t.Fatal(err) + } + var mu sync.Mutex + var reported []string + l := New(Options{Dir: filepath.Join(blocker, "access-log"), Logf: func(f string, a ...any) { + mu.Lock() + reported = append(reported, f) + mu.Unlock() + }}) + h := l.Middleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusTeapot) + _, _ = w.Write([]byte("served")) + })) + for i := 0; i < 3; i++ { + w := serve(h, httptest.NewRequest(http.MethodGet, "/x", nil)) + if w.Code != http.StatusTeapot || w.Body.String() != "served" { + t.Fatalf("request %d altered by the log failure: %d %q", i, w.Code, w.Body.String()) + } + } + l.Close() + mu.Lock() + defer mu.Unlock() + if len(reported) != 1 || !strings.Contains(reported[0], "request was served") { + t.Fatalf("failure reports = %q, want exactly one (rate-limited)", reported) + } +} + +// The long-poll keeps working through the recorder: http.ResponseController reaches Flush through Unwrap/Flush. +func TestAccessLog_FlushPassesThrough(t *testing.T) { + l := New(Options{Dir: t.TempDir()}) + defer l.Close() + var ferr error + h := l.Middleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + ferr = http.NewResponseController(w).Flush() + })) + w := serve(h, httptest.NewRequest(http.MethodGet, "/api/v1/wait", nil)) + if ferr != nil || !w.Flushed { + t.Fatalf("flush through the access log: err=%v flushed=%v", ferr, w.Flushed) + } +} + +// kube-probe's own /healthz is not logged; one that came through the ingress is. +func TestAccessLog_SkipsOnlyTheKubeletProbe(t *testing.T) { + dir := t.TempDir() + l := New(Options{Dir: dir}) + h := l.Middleware(http.HandlerFunc(func(http.ResponseWriter, *http.Request) {})) + probe := httptest.NewRequest(http.MethodGet, "/healthz", nil) + probe.Header.Set("User-Agent", "kube-probe/1.31") + serve(h, probe) + viaIngress := httptest.NewRequest(http.MethodGet, "/healthz", nil) + viaIngress.Header.Set("User-Agent", "kube-probe/1.31") + viaIngress.Header.Set("X-Forwarded-For", "37.191.56.193") + serve(h, viaIngress) + l.Close() + got := readAll(t, dir) + if strings.Count(got, "/healthz") != 1 || !strings.Contains(got, "xff=37.191.56.193") { + t.Fatalf("want exactly the ingress /healthz logged, got:\n%s", got) + } +} diff --git a/hub/internal/api/handler.go b/hub/internal/api/handler.go index 10f892f5..aeb52fc0 100644 --- a/hub/internal/api/handler.go +++ b/hub/internal/api/handler.go @@ -16,6 +16,7 @@ import ( "sync" "time" + "gitea.dooplex.hu/admin/felhom-hub/internal/accesslog" "gitea.dooplex.hu/admin/felhom-hub/internal/assets" "gitea.dooplex.hu/admin/felhom-hub/internal/claim" "gitea.dooplex.hu/admin/felhom-hub/internal/configgen" @@ -195,6 +196,7 @@ func (h *Handler) checkAuthCustomer(r *http.Request) (customerID string, isGloba // Check global key first if h.apiKey != "" && subtle.ConstantTimeCompare([]byte(token), []byte(h.apiKey)) == 1 { + accesslog.Mark(r.Context(), "global") // R-1140: the KIND only, for the hub's access log return "", true, true } @@ -203,6 +205,7 @@ func (h *Handler) checkAuthCustomer(r *http.Request) (customerID string, isGloba if err != nil || cfg == nil { return "", false, false } + accesslog.Mark(r.Context(), "customer") return cfg.CustomerID, false, true } @@ -220,6 +223,7 @@ func (h *Handler) checkAuthHost(r *http.Request) (hostID, customerID string, isG // Global key first (same constant-time compare as checkAuthCustomer). if h.apiKey != "" && subtle.ConstantTimeCompare([]byte(token), []byte(h.apiKey)) == 1 { + accesslog.Mark(r.Context(), "global") return "", "", true, true } @@ -227,6 +231,7 @@ func (h *Handler) checkAuthHost(r *http.Request) (hostID, customerID string, isG if err != nil || host == nil { return "", "", false, false } + accesslog.Mark(r.Context(), "host") return host.HostID, host.CustomerID, false, true } diff --git a/hub/internal/api/r1140_accesslog_test.go b/hub/internal/api/r1140_accesslog_test.go new file mode 100644 index 00000000..2f515254 --- /dev/null +++ b/hub/internal/api/r1140_accesslog_test.go @@ -0,0 +1,61 @@ +package api + +import ( + "net/http/httptest" + "os" + "path/filepath" + "strings" + "testing" + + "gitea.dooplex.hu/admin/felhom-hub/internal/accesslog" + "gitea.dooplex.hu/admin/felhom-hub/internal/store" +) + +// R-1140: the box API's auth helpers mark the identity KIND they established, and the access log writes it — never +// the key. One request per kind (customer, host, global) and one refused; the key values are the negative controls. +func TestAccessLog_APIMarksTheIdentityKindNeverTheKey(t *testing.T) { + h, st, _ := newTestHandler(t) + if err := st.SaveCustomerConfig(&store.CustomerConfig{CustomerID: "c1", APIKey: "CUSTKEY-r1140-aaaa", RetrievalPassword: "p", ConfigJSON: "{}"}); err != nil { + t.Fatal(err) + } + st.UpsertHost(&store.Host{HostID: "h1", CustomerID: "c1", APIKey: "HOSTKEY-r1140-bbbb"}) + dir := t.TempDir() + l := accesslog.New(accesslog.Options{Dir: dir}) + mw := l.Middleware(h) + for _, c := range []struct{ method, path, key string }{ + {"POST", "/api/v1/preferences", "CUSTKEY-r1140-aaaa"}, + {"GET", "/api/v1/hosts/h1/jobs", "HOSTKEY-r1140-bbbb"}, + {"GET", "/api/v1/customers", globalKey}, + {"GET", "/api/v1/customers", "WRONGKEY-r1140-cccc"}, + } { + r := httptest.NewRequest(c.method, c.path, strings.NewReader("{}")) + r.Header.Set("Authorization", "Bearer "+c.key) + mw.ServeHTTP(httptest.NewRecorder(), r) + } + l.Close() + ents, _ := os.ReadDir(dir) + if len(ents) != 1 { + t.Fatalf("%d file(s) in the access log dir, want 1", len(ents)) + } + raw, _ := os.ReadFile(filepath.Join(dir, ents[0].Name())) + got := string(raw) + lines := strings.Split(strings.TrimSpace(got), "\n") + if len(lines) != 4 { + t.Fatalf("%d line(s), want 4:\n%s", len(lines), got) + } + for i, want := range []string{"POST /api/v1/preferences", "GET /api/v1/hosts/h1/jobs", "GET /api/v1/customers", "GET /api/v1/customers"} { + if !strings.Contains(lines[i], want) { + t.Errorf("line %d = %q, want %q", i, lines[i], want) + } + } + for i, kind := range []string{"auth=customer", "auth=host", "auth=global", "auth=-"} { + if !strings.HasSuffix(lines[i], kind) { + t.Errorf("line %d = %q, want it to end with %s", i, lines[i], kind) + } + } + for _, k := range []string{"CUSTKEY", "HOSTKEY", globalKey, "WRONGKEY"} { + if strings.Contains(got, k) { + t.Errorf("a key value reached the access log: %q", k) + } + } +} diff --git a/hub/internal/api/r895_events_test.go b/hub/internal/api/r895_events_test.go new file mode 100644 index 00000000..8222121c --- /dev/null +++ b/hub/internal/api/r895_events_test.go @@ -0,0 +1,22 @@ +package api + +import ( + "testing" + + "gitea.dooplex.hu/admin/felhom-hub/internal/notify" + "gitea.dooplex.hu/admin/felhom-hub/internal/offsitekeys" +) + +// R-895 slice 2: the hub's own snapshot-listing events are operator-only AND hub-origin only — not in +// allowedEventTypes, so no box can POST one to /api/v1/event (a box faking "your history vanished", or drowning a +// real one). Both registers pinned in one test (REUSE.md: fixing one and not the other is the realistic mistake). +func TestR895_SnapshotEventsAreOperatorOnlyAndHubOrigin(t *testing.T) { + for _, et := range []string{offsitekeys.EventSnapshotsVanished, offsitekeys.EventSnapshotsUnexplained} { + if !notify.IsOperatorOnly(et) { + t.Errorf("%s is not operator-only", et) + } + if allowedEventTypes[et] { + t.Errorf("%s is in allowedEventTypes — a box could POST it", et) + } + } +} diff --git a/hub/internal/notify/dispatcher.go b/hub/internal/notify/dispatcher.go index 5cd74b8c..e9c4bf84 100644 --- a/hub/internal/notify/dispatcher.go +++ b/hub/internal/notify/dispatcher.go @@ -789,6 +789,11 @@ var operatorOnlyEvents = map[string]bool{ "offsite_prune_guard_refused": true, // R-833 (v0.129.0): the operator raised ONE window's removal cap — an operator act, logged. "offsite_window_large_grant": true, + // R-895 slice 2 (v0.158.0): the hub's own snapshot listing — files gone outside a clean-up window, files no box run + // explains. Custody facts about a repository the household cannot inspect; listed in the SAME commit that mints + // them. Hub-origin only: deliberately NOT in api.allowedEventTypes, so no box can POST one. + "offsite_snapshots_vanished": true, + "offsite_snapshots_unexplained": true, // OS updates (hub v0.130.0, `11` §8 step 2): run failures, rings, switches and approvals are operator facts. // os_update_applied is deliberately NOT here — it is the household's one line (info: recorded, never mailed). "os_update_failed": true, diff --git a/hub/internal/offsitekeys/offsitekeys_test.go b/hub/internal/offsitekeys/offsitekeys_test.go index 7288c75b..a5996df3 100644 --- a/hub/internal/offsitekeys/offsitekeys_test.go +++ b/hub/internal/offsitekeys/offsitekeys_test.go @@ -31,6 +31,11 @@ func (f *fakeFS) Run(_ context.Context, cmd string, stdin []byte) ([]byte, error return []byte(a[2] + "\n"), nil } return nil, miss + case a[0] == "ls" && a[1] == "-l": // R-895: the listing; the fixture keeps the `ls -l` output under the dir's path + if v, ok := f.files[a[2]]; ok { + return []byte(v), nil + } + return nil, miss case a[0] == "ls": if _, ok := f.files[a[1]]; ok { return []byte(a[1]), nil diff --git a/hub/internal/offsitekeys/service.go b/hub/internal/offsitekeys/service.go index 3116c4ba..5cd77fa5 100644 --- a/hub/internal/offsitekeys/service.go +++ b/hub/internal/offsitekeys/service.go @@ -140,6 +140,10 @@ func (s *Service) MoveAside(ctx context.Context, customerID string) (string, err if err != nil { return "", err } + // R-895: the repository at RepoPath is a new one from now on — tomorrow's listing is a baseline, not a comparison. + if err := s.Store.ClearOffsiteSnapshotListing(customerID); err != nil { + s.logf("[WARN] offsitekeys: clear the snapshot baseline of %s after the move-aside: %v", customerID, err) + } s.logf("[WARN] offsitekeys: moved %s's repository aside: %s -> %s (nothing deleted)", customerID, t.RepoPath, name) s.event(customerID, EventMovedAside, "info", fmt.Sprintf("Off-site: the box asked to set its orphaned repository aside; %s was moved to %s. Nothing was deleted.", t.RepoPath, name), @@ -159,6 +163,9 @@ func (s *Service) PurgeRepos(ctx context.Context, customerID string) error { if err != nil { return err } + if err := s.Store.ClearOffsiteSnapshotListing(customerID); err != nil { + s.logf("[WARN] offsitekeys: clear the snapshot baseline of %s after the purge: %v", customerID, err) + } s.logf("[WARN] offsitekeys: RESET purged %s's off-site folder through its own login: %d path(s) %v", customerID, len(removed), removed) return nil } @@ -216,12 +223,21 @@ func (s *Service) AuditAll(ctx context.Context, windowOpen WindowOpenFunc) []Aud s.logf("[INFO] offsitekeys: audit %s: %d line(s), all pinned append-only", c.CustomerID, o.Result.Lines) } // R-895 measurement slice: the hub's OWN count of the box's snapshot files (read-only, logged, no alarm yet). + // Slice 2 (v0.158.0): the listing is compared with yesterday's (CheckSnapshotListing — vanished / unexplained). if terr == nil { - if l, lerr := s.Reg.ListSnapshots(ctx, t, pw, time.Now().UTC()); lerr != nil { + now := s.now().UTC() + if l, lerr := s.Reg.ListSnapshots(ctx, t, pw, now); lerr != nil { s.logf("[WARN] offsitekeys: snapshots %s: the hub's own listing failed: %v", c.CustomerID, lerr) } else { - s.logf("[INFO] offsitekeys: snapshots %s: the hub's own listing — %d snapshot file(s), %d other line(s), newest %s, oldest %s (R-895 measurement; no alarm yet)", - c.CustomerID, l.Files, l.Other, l.Newest.Format(time.RFC3339), l.Oldest.Format(time.RFC3339)) + // The box's newest reported run beside the provider's newest upload time: the time-zone calibration the + // alarm's slack stands in for (snapTimeSlack) — a different channel from the listing itself. + boxRun := "none reported in 48h" + if runs, rerr := s.Store.OffsiteRunTimesSince(c.CustomerID, now.Add(-48*time.Hour)); rerr == nil && len(runs) > 0 { + boxRun = runs[len(runs)-1].Format(time.RFC3339) + } + s.logf("[INFO] offsitekeys: snapshots %s: the hub's own listing — %d snapshot file(s), %d other line(s), newest %s, oldest %s; box's last reported run %s (R-895)", + c.CustomerID, l.Files, l.Other, l.Newest.Format(time.RFC3339), l.Oldest.Format(time.RFC3339), boxRun) + s.CheckSnapshotListing(c.CustomerID, l, now) } } } diff --git a/hub/internal/offsitekeys/snapshot_watch.go b/hub/internal/offsitekeys/snapshot_watch.go new file mode 100644 index 00000000..312535b6 --- /dev/null +++ b/hub/internal/offsitekeys/snapshot_watch.go @@ -0,0 +1,210 @@ +package offsitekeys + +import ( + "fmt" + "sort" + "strings" + "time" + + "gitea.dooplex.hu/admin/felhom-hub/internal/store" +) + +// R-895 SLICE 2 — THE ALARMS (hub v0.158.0; design `audits/agent-allowlist-rotation-2026-10-17/P4/design-R-895.md` +// §3.2–3.3, origin `audits/night-burndown-2026-10-06/design-R-822.md` option B). +// +// The daily key audit (07:10) already lists the box's restic `snapshots/` over the hub's own login (slice 1). This +// compares today's listing with yesterday's, by NAME, and raises two operator-only events: +// +// - offsite_snapshots_vanished (error): snapshot files are gone that no clean-up window explains. The box's key is +// append-only (decision 69); only a hub-opened window may delete, and each window explains at most what the hub +// let it remove (store.WindowCreditsBetween — the same credits R-435's count detector spends). Unlike R-431/R-435 +// this does NOT trust the box's count: the names are the hub's own read. +// - offsite_snapshots_unexplained (warning): snapshot files appeared whose upload time is not near any off-site run +// the box reported (`offsite.last_run` in its controller reports). That is the injection signature — fakes added +// through the add-only key outside a run. +// +// FALSE-ALARM GUARDS, each a boring reading written down: +// - First listing (or a baseline that cannot be read): it becomes the baseline; no verdict. +// - A set-aside or purged repository clears the baseline (MoveAside, PurgeRepos) — the next listing is a new one. +// - Vanishing is judged only on a PINNED tier (a confirmed append-only key): without it the box may still prune by +// itself, and the daily key check already alarms on the deleting line. +// - A file younger than settleAge at listing time is not judged and not stored; tomorrow it is judged with its run's +// report in hand. +// - The provider shell's time zone is NOT measured (slice 1's log is the measurement): a run explains a file +// uploaded in [last_run − runSpan − timeSlack, last_run + timeSlack]. timeSlack (3 h) covers UTC vs CET/CEST and +// ls's minute truncation; runSpan (6 h) covers a long run (the box writes last_run at the run's END). A first +// upload longer than 6 h can therefore warn once. +// - A failed listing leaves the baseline unchanged; unreadable run reports leave the new files out of it (judged +// again tomorrow) — never a verdict on half data. +// +// NOT built (design §3.1 and the "refuse the next window" half of §3.2): the window's before/after on the hub's own +// count, and refusing a window while unexplained files exist. The second changes what a household's prune does on a +// warning nobody has yet seen fire on a real box; it waits for the first real listings. + +const ( + EventSnapshotsVanished = "offsite_snapshots_vanished" // error: files gone that no clean-up window explains + EventSnapshotsUnexplained = "offsite_snapshots_unexplained" // warning: files no reported box run explains + + snapRunSpan = 6 * time.Hour + snapTimeSlack = 3 * time.Hour + snapSettleAge = time.Hour + snapWindowSlack = 2 * time.Hour // as monitor.windowSlack: a window just before the previous listing still counts +) + +// shortID is a snapshot id as restic prints it (8 characters) — enough for the operator to find it, short in a mail. +func shortID(id string) string { + if len(id) > 8 { + return id[:8] + } + return id +} + +// explainedByRun reports whether a file uploaded at t falls inside some reported run's span. +func explainedByRun(t time.Time, runs []time.Time) bool { + if t.IsZero() { + return false + } + for _, r := range runs { + if !t.Before(r.Add(-snapRunSpan-snapTimeSlack)) && !t.After(r.Add(snapTimeSlack)) { + return true + } + } + return false +} + +// CheckSnapshotListing compares the hub's listing l (taken at now) with the stored baseline, raises the events, and +// stores the new baseline. It returns the counts it judged, for the log and the tests. +func (s *Service) CheckSnapshotListing(customerID string, l SnapshotListing, now time.Time) (vanished, unexplained int) { + now = now.UTC() + next := store.OffsiteSnapshotListing{ListedAt: now, Entries: map[string]time.Time{}} + deferred := 0 + for id, at := range l.Entries { + if !at.IsZero() && at.After(now.Add(-snapSettleAge)) { + deferred++ // judged tomorrow, with its run's report in hand + continue + } + next.Entries[id] = at + } + + prev, ok := s.Store.GetOffsiteSnapshotListing(customerID) + if !ok { + if err := s.Store.SetOffsiteSnapshotListing(customerID, next); err != nil { + s.logf("[WARN] offsitekeys: snapshots %s: could not store the first listing: %v", customerID, err) + return 0, 0 + } + s.logf("[INFO] offsitekeys: snapshots %s: first listing stored as the baseline (%d file(s), %d too new to judge) — no verdict", customerID, len(next.Entries), deferred) + return 0, 0 + } + + var gone, came []string + for id := range prev.Entries { + if _, still := l.Entries[id]; !still { + gone = append(gone, id) + } + } + for id := range next.Entries { + if _, had := prev.Entries[id]; !had { + came = append(came, id) + } + } + sort.Strings(gone) + sort.Strings(came) + + // ── Vanished ──────────────────────────────────────────────────────────────────────────────────── + if len(gone) > 0 { + k, kerr := s.Store.GetOffsiteKey(customerID) + switch { + case kerr != nil || k == nil || k.ConfirmedAt.IsZero(): + s.logf("[INFO] offsitekeys: snapshots %s: %d file(s) gone since %s — not judged: no confirmed append-only key (the box may still prune by itself)", + customerID, len(gone), prev.ListedAt.Format(time.RFC3339)) + default: + credits, unknown := s.Store.WindowCreditsBetween(customerID, prev.ListedAt.Add(-snapWindowSlack), now) + explains := 0 + for _, c := range credits { + explains += c.Explains + } + if unknown || len(gone) > explains { + vanished = len(gone) + why := fmt.Sprintf("the clean-up windows in that time explain at most %d", explains) + if unknown { + why = "the clean-up windows in that time could not be read (judged as unexplained)" + } + s.logf("[ERROR] offsitekeys: snapshots %s: %d snapshot file(s) VANISHED since %s, %s", + customerID, len(gone), prev.ListedAt.Format(time.RFC3339), why) + s.event(customerID, EventSnapshotsVanished, "error", + fmt.Sprintf("Off-site: the hub's own listing of %s's repository shows %d snapshot file(s) gone since %s; %s. "+ + "The box's key cannot delete outside a window. Check the clean-up window ledger and the box before any restore: %s", + customerID, len(gone), prev.ListedAt.Format("2006-01-02 15:04 UTC"), why, idList(gone)), + map[string]any{"vanished": shortIDs(gone), "previous_listing": prev.ListedAt, "window_credit": explains, "windows_unknown": unknown}) + } else { + s.logf("[INFO] offsitekeys: snapshots %s: %d file(s) gone since %s, explained by clean-up windows (up to %d)", + customerID, len(gone), prev.ListedAt.Format(time.RFC3339), explains) + } + } + } + + // ── Appeared, unexplained ─────────────────────────────────────────────────────────────────────── + if len(came) > 0 { + runs, rerr := s.Store.OffsiteRunTimesSince(customerID, prev.ListedAt.Add(-24*time.Hour)) + if rerr != nil { + // The vanish verdict above stands; the new files are left OUT of the stored baseline so tomorrow judges + // them, instead of a verdict on half data (and without repeating the vanish alarm). + for _, id := range came { + delete(next.Entries, id) + } + s.logf("[WARN] offsitekeys: snapshots %s: could not read the box's reported runs (%v) — %d new file(s) judged again tomorrow", customerID, rerr, len(came)) + if err := s.Store.SetOffsiteSnapshotListing(customerID, next); err != nil { + s.logf("[WARN] offsitekeys: snapshots %s: could not store the listing: %v", customerID, err) + } + return vanished, 0 + } + var odd []string + for _, id := range came { + if !explainedByRun(next.Entries[id], runs) { + odd = append(odd, id) + } + } + if len(odd) > 0 { + unexplained = len(odd) + var parts []string + for _, id := range odd { + at := "unknown time" + if t := next.Entries[id]; !t.IsZero() { + at = t.Format("2006-01-02 15:04") + } + parts = append(parts, shortID(id)+" ("+at+")") + } + s.logf("[WARN] offsitekeys: snapshots %s: %d new snapshot file(s) uploaded outside every reported box run (%d run(s) reported since %s): %s", + customerID, len(odd), len(runs), prev.ListedAt.Add(-24*time.Hour).Format(time.RFC3339), strings.Join(parts, ", ")) + s.event(customerID, EventSnapshotsUnexplained, "warning", + fmt.Sprintf("Off-site: %d new snapshot file(s) in %s's repository were uploaded when the box reported no off-site run: %s. "+ + "Fakes added with the box's key would look like this; a crashed run would too. Look at the box before the next clean-up window.", + len(odd), customerID, strings.Join(parts, ", ")), + map[string]any{"unexplained": shortIDs(odd), "runs_reported": len(runs), "previous_listing": prev.ListedAt}) + } else { + s.logf("[INFO] offsitekeys: snapshots %s: %d new snapshot file(s), each inside a reported box run", customerID, len(came)) + } + } + + if err := s.Store.SetOffsiteSnapshotListing(customerID, next); err != nil { + s.logf("[WARN] offsitekeys: snapshots %s: could not store the listing: %v", customerID, err) + } + return vanished, unexplained +} + +func shortIDs(ids []string) []string { + out := make([]string, 0, len(ids)) + for _, id := range ids { + out = append(out, shortID(id)) + } + return out +} + +// idList names at most 20 ids in a message; the details carry them all. +func idList(ids []string) string { + s := shortIDs(ids) + if len(s) > 20 { + return strings.Join(s[:20], ", ") + fmt.Sprintf(" and %d more", len(s)-20) + } + return strings.Join(s, ", ") +} diff --git a/hub/internal/offsitekeys/snapshot_watch_test.go b/hub/internal/offsitekeys/snapshot_watch_test.go new file mode 100644 index 00000000..75564cdb --- /dev/null +++ b/hub/internal/offsitekeys/snapshot_watch_test.go @@ -0,0 +1,250 @@ +package offsitekeys + +import ( + "context" + "fmt" + "strings" + "testing" + "time" + + "gitea.dooplex.hu/admin/felhom-hub/internal/notify" + "gitea.dooplex.hu/admin/felhom-hub/internal/store" +) + +// R-895 slice 2: the hub's own listing, compared day to day. Fixtures are `ls -l` outputs in the provider's shape +// (slice 1's parser) on a real store; the clock is the wall clock because the window ledger stamps rows with SQLite's +// datetime('now'). + +const snapDir = "/home/felhom-repo/snapshots" + +func snapID(n int) string { return fmt.Sprintf("%08x%056x", 0xa1b2c300+n, n+1) } + +// lsOut renders `ls -l` lines for ids uploaded at the given times (year-less form, as the provider prints recent files). +func lsOut(files map[string]time.Time) string { + var b strings.Builder + b.WriteString("total 8\n") + for id, at := range files { + fmt.Fprintf(&b, "-rw------- 1 u1-sub4 u1-sub4 324 %s %s\n", at.UTC().Format("Jan _2 15:04"), id) + } + return b.String() +} + +type evt struct{ typ, sev, msg string } + +// watchFixture: a provisioned customer whose box key is registered AND confirmed (the pinned tier), events captured. +func watchFixture(t *testing.T) (*Service, *fakeFS, *[]evt) { + t.Helper() + s, fs, _ := svcFixture(t) + var events []evt + s.Emit = func(_, typ, sev, msg, _, _ string) { events = append(events, evt{typ, sev, msg}) } + pub, fp := newKey(t) + if _, err := s.RegisterKey(context.Background(), "c1", pub); err != nil { + t.Fatal(err) + } + if _, err := s.ConfirmKey(context.Background(), "c1", fp); err != nil { + t.Fatal(err) + } + events = nil + return s, fs, &events +} + +func ofType(events []evt, typ string) []evt { + var out []evt + for _, e := range events { + if e.typ == typ { + out = append(out, e) + } + } + return out +} + +func reportRun(t *testing.T, st *store.Store, at time.Time) { + t.Helper() + if err := st.SaveReport("c1", []byte(`{"controller_version":"0.330.0","offsite":{"enabled":true,"last_run":"`+at.UTC().Format(time.RFC3339)+`"}}`)); err != nil { + t.Fatal(err) + } +} + +// THE CONSEQUENCE, through the production entry point (the 07:10 AuditAll): day 1 is the baseline (no alarm), day 2 +// shows three snapshots gone with no clean-up window → ONE offsite_snapshots_vanished (error), and the same listing on +// day 3 does not repeat it. RED-PROOF (REPORT, 2026-10-17 night): with the `len(gone) > explains` verdict replaced by +// `false`, this fails with `vanished events = 0, want 1`. +func TestSnapshotWatch_VanishedOutsideAWindowAlarmsOnce(t *testing.T) { + s, fs, events := watchFixture(t) + now := time.Now().UTC() + files := map[string]time.Time{} + for i := 0; i < 10; i++ { + files[snapID(i)] = now.Add(-time.Duration(48+i) * time.Hour).Truncate(time.Minute) + } + fs.files[snapDir] = lsOut(files) + s.AuditAll(context.Background(), nil) + if n := len(ofType(*events, EventSnapshotsVanished)) + len(ofType(*events, EventSnapshotsUnexplained)); n != 0 { + t.Fatalf("the first listing is a baseline: %d snapshot event(s), want 0 (%+v)", n, *events) + } + if _, ok := s.Store.GetOffsiteSnapshotListing("c1"); !ok { + t.Fatal("the first listing was not stored as the baseline") + } + + for i := 0; i < 3; i++ { + delete(files, snapID(i)) + } + fs.files[snapDir] = lsOut(files) + s.AuditAll(context.Background(), nil) + v := ofType(*events, EventSnapshotsVanished) + if len(v) != 1 { + t.Fatalf("vanished events = %d, want 1 (events: %+v)", len(v), *events) + } + if v[0].sev != "error" || !strings.Contains(v[0].msg, "3 snapshot file(s) gone") || !strings.Contains(v[0].msg, shortID(snapID(0))) { + t.Fatalf("event = %+v — want severity error naming 3 files and the first id", v[0]) + } + + s.AuditAll(context.Background(), nil) + if n := len(ofType(*events, EventSnapshotsVanished)); n != 1 { + t.Fatalf("the same listing again raised the alarm again: %d events, want still 1", n) + } +} + +// A clean-up window the hub opened explains up to what it removed; more than that still alarms. +func TestSnapshotWatch_WindowExplainsUpToItsCredit(t *testing.T) { + for _, tc := range []struct { + name string + gone int + wantAlarm bool + }{{"within the window's removal", 4, false}, {"beyond it", 7, true}} { + t.Run(tc.name, func(t *testing.T) { + s, _, events := watchFixture(t) + now := time.Now().UTC() + all := map[string]time.Time{} + for i := 0; i < 20; i++ { + all[snapID(i)] = now.Add(-time.Duration(48+i) * time.Hour).Truncate(time.Minute) + } + if err := s.Store.SetOffsiteSnapshotListing("c1", store.OffsiteSnapshotListing{ListedAt: now.Add(-24 * time.Hour), Entries: all}); err != nil { + t.Fatal(err) + } + // The window: 20 → 15, so it explains 5 removals (min of its cap 10 and its reported drop). + id, err := s.Store.OpenOffsiteWindowRow("c1", now.Add(windowLength), 20, MaxRemove(20)) + if err != nil { + t.Fatal(err) + } + if _, err := s.Store.CloseOffsiteWindowRow(id, 15, "pruned", "box"); err != nil { + t.Fatal(err) + } + cur := map[string]time.Time{} + for k, v := range all { + cur[k] = v + } + for i := 0; i < tc.gone; i++ { + delete(cur, snapID(i)) + } + v, _ := s.CheckSnapshotListing("c1", SnapshotListing{Files: len(cur), Entries: cur}, time.Now().UTC().Add(time.Second)) + got := len(ofType(*events, EventSnapshotsVanished)) == 1 + if got != tc.wantAlarm || (v > 0) != tc.wantAlarm { + t.Fatalf("%d gone with a window crediting 5: alarm=%v (vanished=%d), want %v", tc.gone, got, v, tc.wantAlarm) + } + }) + } +} + +// A new file uploaded inside a run the box reported is explained; one uploaded at a time no run explains warns — and a +// file younger than an hour is neither judged nor stored (tomorrow judges it with its run's report in hand). +func TestSnapshotWatch_AppearedOutsideEveryRunWarns(t *testing.T) { + s, _, events := watchFixture(t) + now := time.Now().UTC() + old := map[string]time.Time{snapID(0): now.Add(-72 * time.Hour).Truncate(time.Minute)} + if err := s.Store.SetOffsiteSnapshotListing("c1", store.OffsiteSnapshotListing{ListedAt: now.Add(-24 * time.Hour), Entries: old}); err != nil { + t.Fatal(err) + } + run := now.Add(-8 * time.Hour).Truncate(time.Second) + reportRun(t, s.Store, run) + + inRun := snapID(1) // uploaded 20 minutes before the run ended + fake := snapID(2) // uploaded 4 hours AFTER the run ended — no run explains it + young := snapID(3) // 10 minutes old at listing time + cur := map[string]time.Time{ + snapID(0): old[snapID(0)], + inRun: run.Add(-20 * time.Minute).Truncate(time.Minute), + fake: run.Add(4 * time.Hour).Truncate(time.Minute), + young: now.Add(-10 * time.Minute).Truncate(time.Minute), + } + _, u := s.CheckSnapshotListing("c1", SnapshotListing{Files: len(cur), Entries: cur}, now) + w := ofType(*events, EventSnapshotsUnexplained) + if u != 1 || len(w) != 1 { + t.Fatalf("unexplained=%d events=%d, want exactly the one fake (events %+v)", u, len(w), *events) + } + if w[0].sev != "warning" || !strings.Contains(w[0].msg, shortID(fake)) || strings.Contains(w[0].msg, shortID(inRun)) { + t.Fatalf("event = %+v — want a warning naming %s and not %s", w[0], shortID(fake), shortID(inRun)) + } + base, _ := s.Store.GetOffsiteSnapshotListing("c1") + if _, ok := base.Entries[young]; ok { + t.Fatal("a 10-minute-old file was stored in the baseline — it must be judged tomorrow, not silently accepted") + } + if _, ok := base.Entries[fake]; !ok { + t.Fatal("the judged file is not in the new baseline — tomorrow would warn again") + } +} + +// The repository moved aside → the baseline is dropped, so the new, empty repository is a baseline and not "every +// snapshot vanished". +func TestSnapshotWatch_MoveAsideResetsTheBaseline(t *testing.T) { + s, fs, events := watchFixture(t) + now := time.Now().UTC() + if err := s.Store.SetOffsiteSnapshotListing("c1", store.OffsiteSnapshotListing{ListedAt: now.Add(-24 * time.Hour), + Entries: map[string]time.Time{snapID(0): now.Add(-72 * time.Hour)}}); err != nil { + t.Fatal(err) + } + fs.dirs["/home/felhom-repo"] = true + if _, err := s.MoveAside(context.Background(), "c1"); err != nil { + t.Fatal(err) + } + if _, ok := s.Store.GetOffsiteSnapshotListing("c1"); ok { + t.Fatal("the baseline survived a move-aside") + } + s.CheckSnapshotListing("c1", SnapshotListing{}, now) + if n := len(ofType(*events, EventSnapshotsVanished)); n != 0 { + t.Fatalf("an empty new repository after a move-aside raised %d vanished event(s)", n) + } +} + +// Without a confirmed append-only key the box may prune by itself: vanishing is not judged. +func TestSnapshotWatch_UnpinnedTierDoesNotJudgeVanishing(t *testing.T) { + s, _, _ := svcFixture(t) + var events []evt + s.Emit = func(_, typ, sev, msg, _, _ string) { events = append(events, evt{typ, sev, msg}) } + now := time.Now().UTC() + if err := s.Store.SetOffsiteSnapshotListing("c1", store.OffsiteSnapshotListing{ListedAt: now.Add(-24 * time.Hour), + Entries: map[string]time.Time{snapID(0): now.Add(-72 * time.Hour), snapID(1): now.Add(-73 * time.Hour)}}); err != nil { + t.Fatal(err) + } + s.CheckSnapshotListing("c1", SnapshotListing{Entries: map[string]time.Time{snapID(1): now.Add(-73 * time.Hour)}}, now) + if n := len(ofType(events, EventSnapshotsVanished)); n != 0 { + t.Fatalf("unpinned tier: %d vanished event(s), want 0", n) + } +} + +// Both events are operator-only (a missing customerMessages entry is NOT a block — the v0.78.0 defect). +func TestSnapshotWatch_EventsAreOperatorOnly(t *testing.T) { + for _, et := range []string{EventSnapshotsVanished, EventSnapshotsUnexplained} { + if !notify.IsOperatorOnly(et) { + t.Errorf("%s is not in notify.operatorOnlyEvents — it would reach a household as raw English", et) + } + } +} + +func TestExplainedByRun_Bounds(t *testing.T) { + r := time.Date(2026, 10, 17, 3, 0, 0, 0, time.UTC) + for _, tc := range []struct { + at time.Time + want bool + }{ + {r, true}, + {r.Add(snapTimeSlack), true}, + {r.Add(snapTimeSlack + time.Minute), false}, + {r.Add(-snapRunSpan - snapTimeSlack), true}, + {r.Add(-snapRunSpan - snapTimeSlack - time.Minute), false}, + {time.Time{}, false}, + } { + if got := explainedByRun(tc.at, []time.Time{r}); got != tc.want { + t.Errorf("upload %v vs run %v: explained=%v, want %v", tc.at, r, got, tc.want) + } + } +} diff --git a/hub/internal/offsitekeys/snapshots.go b/hub/internal/offsitekeys/snapshots.go index 233283da..c173bd25 100644 --- a/hub/internal/offsitekeys/snapshots.go +++ b/hub/internal/offsitekeys/snapshots.go @@ -22,6 +22,9 @@ type SnapshotListing struct { Other int // lines that are not (a header, a temp file, an unparsable line) Newest time.Time // zero when no time could be read Oldest time.Time + // Entries (slice 2, hub v0.158.0): each snapshot id with its upload time (zero when unreadable). A restic + // snapshot file is written once and never changed, so its mtime is its upload time. + Entries map[string]time.Time } var snapshotID = regexp.MustCompile(`^[0-9a-f]{64}$`) @@ -53,7 +56,12 @@ func parseLsL(out string, now time.Time) SnapshotListing { continue } l.Files++ + if l.Entries == nil { + l.Entries = map[string]time.Time{} + } + l.Entries[f[len(f)-1]] = time.Time{} if ts, ok := lsTime(f[len(f)-4], f[len(f)-3], f[len(f)-2], now); ok { + l.Entries[f[len(f)-1]] = ts if l.Newest.IsZero() || ts.After(l.Newest) { l.Newest = ts } diff --git a/hub/internal/store/offsite_snapshots.go b/hub/internal/store/offsite_snapshots.go new file mode 100644 index 00000000..3d5236f9 --- /dev/null +++ b/hub/internal/store/offsite_snapshots.go @@ -0,0 +1,96 @@ +package store + +import ( + "encoding/json" + "sort" + "time" +) + +// R-895 slice 2 (hub v0.158.0): the hub's OWN listing of a box's off-site `snapshots/` directory, kept between two +// daily audits so the next one can tell which snapshot files vanished and which appeared. Names and upload times only +// — never contents (`07` §8a custody). One hub_settings row per customer (≈ 70 names × ~90 bytes), the same per-key +// pattern as ForeignKeyArchiveSignature. + +const offsiteSnapshotListingKeyPrefix = "offsite_snapshot_listing:" + +// OffsiteSnapshotListing is the stored baseline: when it was listed, and each snapshot id with its upload time. +type OffsiteSnapshotListing struct { + ListedAt time.Time `json:"listed_at"` + Entries map[string]time.Time `json:"entries"` +} + +// GetOffsiteSnapshotListing returns the stored baseline; ok=false when there is none (or it does not parse — a +// baseline that cannot be read is no baseline, and no baseline means no verdict). +func (s *Store) GetOffsiteSnapshotListing(customerID string) (OffsiteSnapshotListing, bool) { + raw := s.getSetting(offsiteSnapshotListingKeyPrefix + customerID) + if raw == "" { + return OffsiteSnapshotListing{}, false + } + var l OffsiteSnapshotListing + if err := json.Unmarshal([]byte(raw), &l); err != nil || l.ListedAt.IsZero() { + return OffsiteSnapshotListing{}, false + } + if l.Entries == nil { + l.Entries = map[string]time.Time{} + } + return l, true +} + +// SetOffsiteSnapshotListing replaces the stored baseline. +func (s *Store) SetOffsiteSnapshotListing(customerID string, l OffsiteSnapshotListing) error { + b, err := json.Marshal(l) + if err != nil { + return err + } + return s.setSetting(offsiteSnapshotListingKeyPrefix+customerID, string(b)) +} + +// ClearOffsiteSnapshotListing drops the baseline (the repository was set aside or purged — the next listing is a +// fresh baseline, never a comparison against a different repository). +func (s *Store) ClearOffsiteSnapshotListing(customerID string) error { + _, err := s.db.Exec(`DELETE FROM hub_settings WHERE key = ?`, offsiteSnapshotListingKeyPrefix+customerID) + return err +} + +// OffsiteRunTimesSince returns the distinct off-site run times (`offsite.last_run`, written by the box at the END of +// every run — scheduled, manual, catch-up or retry) carried by the customer's controller reports received after +// `since`, oldest first. A run is reported in every report until the next run, so a 15-minute report cadence sees +// every run that is at least one report apart. Capped at 5000 reports (≈ 50 days at the measured cadence). +func (s *Store) OffsiteRunTimesSince(customerID string, since time.Time) ([]time.Time, error) { + rows, err := s.db.Query(`SELECT report_json FROM reports WHERE customer_id = ? AND received_at > ? ORDER BY id LIMIT 5000`, + customerID, since.UTC().Format("2006-01-02 15:04:05")) + if err != nil { + return nil, err + } + defer rows.Close() + seen := map[time.Time]bool{} + var out []time.Time + for rows.Next() { + var reportJSON string + if err := rows.Scan(&reportJSON); err != nil { + return nil, err + } + var p struct { + Offsite *struct { + LastRun string `json:"last_run"` + } `json:"offsite"` + } + if json.Unmarshal([]byte(reportJSON), &p) != nil || p.Offsite == nil || p.Offsite.LastRun == "" { + continue + } + t, err := time.Parse(time.RFC3339, p.Offsite.LastRun) + if err != nil { + continue + } + t = t.UTC() + if !seen[t] { + seen[t] = true + out = append(out, t) + } + } + if err := rows.Err(); err != nil { + return nil, err + } + sort.Slice(out, func(i, j int) bool { return out[i].Before(out[j]) }) + return out, nil +} diff --git a/hub/internal/web/agent_only_vouch_test.go b/hub/internal/web/agent_only_vouch_test.go new file mode 100644 index 00000000..cdcbea58 --- /dev/null +++ b/hub/internal/web/agent_only_vouch_test.go @@ -0,0 +1,82 @@ +package web + +import ( + "net/http" + "net/http/httptest" + "net/url" + "strings" + "testing" + + "gitea.dooplex.hu/admin/felhom-hub/internal/store" +) + +// Agent-only vouch (`09` §3 decision 250 items 3–4, hub v0.158.0). The golden is baked weekly while the floor carries +// controller releases, so mid-week the vouched golden is behind the fleet. The R-120 gate guards a golden SELECTION: +// an unchanged golden (same version, same sha) is not a selection and must not block an agent-only save; a changed +// golden is judged exactly as before. Both tests drive handleSetArtifacts — the only UI writer of the manifest. + +func postArtifacts(t *testing.T, s *Server, form url.Values) *httptest.ResponseRecorder { + t.Helper() + r := httptest.NewRequest(http.MethodPost, "/configuration/artifacts", strings.NewReader(form.Encode())) + r.Header.Set("Content-Type", "application/x-www-form-urlencoded") + w := httptest.NewRecorder() + s.handleSetArtifacts(w, r) + return w +} + +// The mid-week situation: golden 0.330.0 vouched on Sunday, the floor has since carried the fleet to 0.335.0, and the +// operator vouches a new agent. RED-PROOF (REPORT, 2026-10-17 night): with the `!goldenUnchanged` condition removed +// from the gate, this fails: `agent-only vouch refused: Location="/configuration?flash=golden_behind_fleet"`. +func TestVouchAgentOnlyWithStaleGoldenIsSaved(t *testing.T) { + s, st := newTestServer(t) + seedReport(t, st, "demo", "0.335.0") + golden := strings.Repeat("b", 64) + if err := st.SetArtifactManifest(store.ArtifactManifest{ + AgentVersion: "0.159.0", AgentSHA256: strings.Repeat("a", 64), + GoldenVersion: "0.330.0", GoldenSHA256: golden, MinAgent: "0.150.0", + }); err != nil { + t.Fatal(err) + } + w := postArtifacts(t, s, url.Values{ + "agent_version": {"0.160.0"}, "agent_sha256": {strings.Repeat("c", 64)}, + "golden_version": {"0.330.0"}, "golden_sha256": {golden}, "min_agent": {"0.150.0"}, + }) + if loc := w.Header().Get("Location"); !strings.Contains(loc, "flash=artifacts_set") { + t.Fatalf("agent-only vouch refused: Location=%q, want flash=artifacts_set", loc) + } + m := st.GetArtifactManifest() + if m.AgentVersion != "0.160.0" || m.AgentSHA256 != strings.Repeat("c", 64) { + t.Fatalf("agent not saved: agent=%s sha=%s…", m.AgentVersion, m.AgentSHA256[:4]) + } + if m.GoldenVersion != "0.330.0" || m.GoldenSHA256 != golden || m.MinAgent != "0.150.0" { + t.Fatalf("golden/MinAgent moved on an agent-only save: %+v", m) + } +} + +// A golden CHANGED to an older one is still refused, even though the agent changes in the same save — and nothing is +// written. Also the same version under a different sha (a re-push) is a changed golden. +func TestVouchGoldenChangedToOlderIsStillRefused(t *testing.T) { + s, st := newTestServer(t) + seedReport(t, st, "demo", "0.335.0") + cur := store.ArtifactManifest{ + AgentVersion: "0.159.0", AgentSHA256: strings.Repeat("a", 64), + GoldenVersion: "0.330.0", GoldenSHA256: strings.Repeat("b", 64), + } + if err := st.SetArtifactManifest(cur); err != nil { + t.Fatal(err) + } + for name, form := range map[string]url.Values{ + "older version": {"agent_version": {"0.160.0"}, "agent_sha256": {strings.Repeat("c", 64)}, + "golden_version": {"0.329.0"}, "golden_sha256": {strings.Repeat("d", 64)}}, + "same version, other sha": {"agent_version": {"0.160.0"}, "agent_sha256": {strings.Repeat("c", 64)}, + "golden_version": {"0.330.0"}, "golden_sha256": {strings.Repeat("e", 64)}}, + } { + w := postArtifacts(t, s, form) + if loc := w.Header().Get("Location"); !strings.Contains(loc, "golden_behind_fleet") { + t.Errorf("%s: Location=%q, want the golden_behind_fleet refusal", name, loc) + } + if m := st.GetArtifactManifest(); m != cur { + t.Errorf("%s: refused but the manifest changed: %+v", name, m) + } + } +} diff --git a/hub/internal/web/configs.go b/hub/internal/web/configs.go index 5b522fa3..f6c62cba 100644 --- a/hub/internal/web/configs.go +++ b/hub/internal/web/configs.go @@ -1532,7 +1532,25 @@ func (s *Server) handleSetArtifacts(w http.ResponseWriter, r *http.Request) { // FAIL-OPEN, deliberately, in exactly two cases: an empty golden field (clearing the manifest is a // legitimate operator act) and an unknown fleet version (no guest has reported one — a brand-new hub // must be able to vouch its first golden). Neither is the drift this catches. - if goldenVer != "" { + // + // AGENT-ONLY VOUCH (`09` §3 decision 250 items 3–4, hub v0.158.0). The golden is baked WEEKLY while + // controller releases ride the floor, so for most of a week the vouched golden is behind the fleet — and + // this gate then refused EVERY save, including one that changes only the agent. An agent vouch mid-week + // was impossible without a re-bake. The gate guards a golden SELECTION: when the submitted golden is the + // one already vouched (same version AND same sha256), nothing about the golden changes and the gate does + // not apply. A changed golden — another version, or the same version with another sha (a re-push) — is + // judged exactly as before. The MinAgent rule for a floor (a floor whose MinAgent is above the vouched + // agent is never set) lives on the floor path and is untouched. Pinned by + // TestVouchAgentOnlyWithStaleGoldenIsSaved / TestVouchGoldenChangedToOlderIsStillRefused. + cur := s.store.GetArtifactManifest() + goldenUnchanged := goldenVer != "" && goldenVer == cur.GoldenVersion && goldenSHA == cur.GoldenSHA256 + if goldenUnchanged { + if newest := s.store.NewestReportedControllerVersion(); newest != "" && compareVersions(goldenVer, newest) < 0 { + s.logger.Printf("[INFO] artifact vouch: golden %s unchanged (behind the fleet's %s — the weekly bake) — the R-120 gate does not apply to an unchanged golden; saving agent=%s min_agent=%q", + goldenVer, newest, agentVer, minAgent) + } + } + if goldenVer != "" && !goldenUnchanged { if newest := s.store.NewestReportedControllerVersion(); newest != "" && compareVersions(goldenVer, newest) < 0 { s.logger.Printf("[WARN] artifact vouch REFUSED: golden %s is older than the newest controller the fleet reports (%s) — "+ "a fresh install would land on stale application code (R-120)", goldenVer, newest) diff --git a/hub/internal/web/server.go b/hub/internal/web/server.go index 6ba966db..2ba60202 100644 --- a/hub/internal/web/server.go +++ b/hub/internal/web/server.go @@ -16,6 +16,7 @@ import ( "sync" "time" + "gitea.dooplex.hu/admin/felhom-hub/internal/accesslog" "gitea.dooplex.hu/admin/felhom-hub/internal/assets" "gitea.dooplex.hu/admin/felhom-hub/internal/claim" "gitea.dooplex.hu/admin/felhom-hub/internal/gitea" @@ -913,6 +914,7 @@ func (s *Server) RequireAuth(next http.Handler) http.Handler { sess, ok := s.sessions[cookie.Value] s.sessionsMu.RUnlock() if ok && time.Now().Before(sess.expiresAt) { + accesslog.Mark(r.Context(), "session") // R-1140: the KIND only next.ServeHTTP(w, r) return } @@ -921,6 +923,7 @@ func (s *Server) RequireAuth(next http.Handler) http.Handler { // Check basic auth (for programmatic/CLI access) _, password, ok := r.BasicAuth() if ok && bcrypt.CompareHashAndPassword([]byte(s.effectivePasswordHash()), []byte(password)) == nil { + accesslog.Mark(r.Context(), "basic") next.ServeHTTP(w, r) return } diff --git a/hub/internal/web/tokens.go b/hub/internal/web/tokens.go index 4fecae23..3cd21611 100644 --- a/hub/internal/web/tokens.go +++ b/hub/internal/web/tokens.go @@ -10,6 +10,7 @@ import ( "strings" "time" + "gitea.dooplex.hu/admin/felhom-hub/internal/accesslog" "gitea.dooplex.hu/admin/felhom-hub/internal/store" ) @@ -109,6 +110,7 @@ func (s *Server) serveWithToken(w http.ResponseWriter, r *http.Request, next htt if err := s.store.TouchAPIToken(t.ID, clientAddr(r)); err != nil { s.logger.Printf("[WARN] access token %q: last-used not recorded: %v", t.Name, err) } + accesslog.Mark(r.Context(), "token") // R-1140: the KIND only — the name is in the line below, the token nowhere rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} next.ServeHTTP(rec, r.WithContext(context.WithValue(r.Context(), tokenCtxKey{}, t))) s.logger.Printf("[INFO] access token %q: %s %s → %d", t.Name, method, path, rec.status) diff --git a/scripts/CHANGELOG.md b/scripts/CHANGELOG.md index 98a579fa..3a7f35ff 100644 --- a/scripts/CHANGELOG.md +++ b/scripts/CHANGELOG.md @@ -1,3 +1,16 @@ +## 2026-10-18 — `felhom-host-install.sh --rotate-recovery-only` (R-1141); not yet tagged + +A new flag runs step 4b ALONE: a new random root@pam password, set with chpasswd and re-vaulted to the hub with the +host key from the agent's own config. It never installs or changes the agent, its config, the root files or a guest; +no passphrase, no customer id. Refuses byo (`--mode byo`, and an agent config whose `deployment_mode` is not +`appliance` — absent counts as byo), refuses with --uninstall/--adopt-pool/--rescope-acl/--preflight-only/--resume, +needs root (except --dry-run), and asks the hub's `/healthz` before the password changes. `step_break_glass` moved, +byte-identical, ahead of the argument parse (the new mode is dispatched before the install's mode validation). +Harness: INV-1 now counts two appliance-gated call sites; new cases R1141-a..k; red-proved by four mutations. The +default install path: same harness verdicts old vs new, identical non-PVE transcripts for 9 argv sets, and on demo-hp +an identical `--preflight-only` transcript (except a live free-RAM number and a line number). Pushing to `main` +publishes nothing — this rides the next `installer-v…` tag. SCRIPT_VERSION unchanged. + ## 2026-10-17 — the uninstall removes agent v0.159.0's new root helper (R-1012); not yet tagged `felhom-host-install.sh --uninstall` removes `/usr/local/sbin/felhom-thin-check`, the read-only orphan-thin check the diff --git a/scripts/felhom-host-install.sh b/scripts/felhom-host-install.sh index 2345a7ae..0f3bce21 100644 --- a/scripts/felhom-host-install.sh +++ b/scripts/felhom-host-install.sh @@ -173,6 +173,16 @@ # --acl-storages "a b c" override the storages the scoped ACL grants Datastore.* on # (default: "local local-lvm felhom-pbs"). Used by fresh install + --rescope-acl. # +# Rotate the console password ALONE (R-1141 — no passphrase, no customer id): +# --rotate-recovery-only step 4b and nothing else: a new random root@pam password, set with chpasswd and +# re-vaulted to the hub with the host key in the agent's own config. Never installs +# or changes the agent, its config, the root files, a guest or the install state +# (except the break_glass mark). Refuses byo (also a config with deployment_mode +# other than "appliance"), refuses with any other mode flag, and checks the hub +# answers before it changes the password. Takes --dry-run. The hub is the one in +# the agent config (--hub-url is not used). Do NOT use it on a host whose +# root@pam was set by hand to a known password — it replaces it with a random one. +# # State (idempotent/resumable): /var/lib/felhom-install/state.json # Agent config written 0600 to the systemd unit's -config path # (auto-detected; else /etc/felhom-agent/agent.json). @@ -270,6 +280,7 @@ REMOVE_GOLDEN=false # --remove-golden: also delete the golden vzdump during ADOPT_POOL=false # --adopt-pool: retrofit an EXISTING Felhom guest into the felhom pool (non-destructive) RESCOPE_ACL=false # --rescope-acl: migrate an existing install from the broad-/ token to the scoped ACL ROTATE_RECOVERY=false # --rotate-recovery: regenerate + re-vault the break-glass root@pam password (TASK G1) +ROTATE_RECOVERY_ONLY=false # --rotate-recovery-only: step 4b ALONE, from the agent config's hub key (R-1141) ENABLE_OOB=false # the OOB belt (TASK H1). DEFAULT-ON for appliance mode since v1.25.0 (F9 ruling # 2026-07-23: an operator-owned box must be reachable OOB) — see the appliance # default below; --enable-oob forces it, --no-oob opts an appliance box out. @@ -1605,6 +1616,60 @@ run_rescope_acl() { return 0 } +#------------------------------------------------------------------------------- +# STEP 4b — break-glass credential (TASK G1): generate + set + vault the root@pam console password +#------------------------------------------------------------------------------- +# The human fallback for when BOTH the sshd path AND the agent-independent auto-heal (layers 1+2) have +# failed: a strong root@pam password lets the operator reach the PVE WEB CONSOLE (pveproxy :8006 — a +# failure domain distinct from sshd) and run the one-line /run/sshd fix. Generated with strong entropy, +# set via chpasswd, and vaulted to the hub over the enroll-authenticated channel (host api_key). The +# password is NEVER logged, printed, or written to any file — it goes stdin→chpasswd and stdin→curl +# only (SPIKE-felhom-sshd finding #9 / TASK G1 trap 3). Idempotent: skipped if already vaulted unless +# --rotate-recovery (a re-set would strand the operator's saved copy). +# Defined HERE, ahead of the argument parse (R-1141): --rotate-recovery-only is dispatched before the +# install's mode validation and calls it. Moved unchanged; the install still calls it from Main. +step_break_glass() { + log_step "4b/8 break-glass credential (root@pam console password → hub vault)" + if [[ -z "${HOST_ID:-}" || -z "${HOST_API_KEY:-}" ]]; then + log_warn " no host_id/api_key (enroll skipped?) — cannot vault a recovery credential; skipping" + return 0 + fi + if $DRY_RUN; then + log_dry "openssl rand → strong root@pam password (never logged) ; chpasswd ; PUT $HUB_URL/api/v1/hosts/$HOST_ID/recovery-credential (Bearer host key)" + _state_mark break_glass; return 0 + fi + if _state_has break_glass && ! $ROTATE_RECOVERY; then + log_skip " recovery credential already vaulted (use --rotate-recovery to regenerate)" + return 0 + fi + # Strong password: 24 url-safe bytes (~144 bits). Kept ONLY in a local shell var, never on disk. + local newpw + newpw=$(openssl rand -base64 24 2>/dev/null | tr -d '\n' | tr '+/' '-_') + [[ ${#newpw} -ge 24 ]] || die "failed to generate a strong recovery password" + # Set root@pam (= the Linux root user on PVE) via chpasswd on STDIN — no argv, no log. + if ! printf 'root:%s\n' "$newpw" | chpasswd 2>/dev/null; then + newpw="" # scrub + die "chpasswd failed to set the root@pam recovery password" + fi + # Vault to the hub over the host-key-authenticated channel; password only on stdin (-d @-). + local code + code=$(printf '{"username":"root@pam","password":"%s"}' "$newpw" \ + | curl -sS -o /dev/null -w '%{http_code}' -X PUT \ + "$HUB_URL/api/v1/hosts/$HOST_ID/recovery-credential" \ + -H "Authorization: Bearer $HOST_API_KEY" -H 'Content-Type: application/json' -d @- 2>/dev/null) + newpw="" # scrub the plaintext from the shell var the moment it is vaulted + case "$code" in + 200) log_success " root@pam password set + vaulted to the hub (retrieve via the operator /admin path; never logged here)" + # Drill F-8: say this OUT LOUD — the operator was live-surprised by a 401 at the PVE + # GUI. Pointer only, never the credential. + log_warn " NOTE: the root@pam password just CHANGED — the old one now fails at the PVE web GUI (:8006)." + log_warn " Retrieve the new one at hub → host page (vaulted recovery credential)." ;; + 401|403) die "recovery-credential vault rejected ($code) — host key/authorization problem" ;; + *) die "recovery-credential vault failed (HTTP $code)" ;; + esac + _state_mark break_glass +} + #------------------------------------------------------------------------------- # Arg parse #------------------------------------------------------------------------------- @@ -1638,6 +1703,7 @@ while [[ $# -gt 0 ]]; do --adopt-pool) ADOPT_POOL=true; shift ;; --rescope-acl) RESCOPE_ACL=true; shift ;; --rotate-recovery) ROTATE_RECOVERY=true; shift ;; + --rotate-recovery-only) ROTATE_RECOVERY_ONLY=true; shift ;; --enable-oob) ENABLE_OOB=true; shift ;; --no-oob) NO_OOB=true; shift ;; --acl-storages) read -ra PVE_STORAGES <<< "$2"; shift 2 ;; @@ -1649,6 +1715,83 @@ while [[ $# -gt 0 ]]; do esac done +#=============================================================================== +# ROTATE-RECOVERY-ONLY MODE (R-1141) — step 4b and NOTHING else. The full re-run with --rotate-recovery +# also reinstalls the vouched agent and the root files (on a box ahead of the vouched agent it would move +# the agent back). This mode reads the hub URL, host id and host key from the agent's own config and +# calls step_break_glass; no passphrase, no hub enroll, no agent/config/guest step. Dispatched FIRST, so +# a combination with another mode flag is refused before that mode can run. +#=============================================================================== +if $ROTATE_RECOVERY_ONLY; then + if $UNINSTALL || $ADOPT_POOL || $RESCOPE_ACL || $PREFLIGHT_ONLY || $RESUME; then + die "--rotate-recovery-only runs alone (not with --uninstall, --adopt-pool, --rescope-acl, --preflight-only or --resume) — nothing changed" + fi + if [[ -n "$MODE" && "$MODE" != "appliance" ]]; then + die "--rotate-recovery-only is not allowed in $MODE mode (byo never touches root@pam — there is no recovery credential to rotate)" + fi + $DRY_RUN || [[ $EUID -eq 0 ]] || die "must run as root" + echo "" + log_info "felhom-host-install v${SCRIPT_VERSION} — mode=rotate-recovery-only" + $DRY_RUN && log_warn "DRY-RUN: no mutations will be performed" + echo "" + # The agent config (0600, root): the same path resolution as the preflight. FELHOM_AGENT_CONFIG is a + # test-harness-only override (hostinstall-mode-harness.sh), like FELHOM_INSTALL_STATE_DIR. + AGENT_CONFIG="${FELHOM_AGENT_CONFIG:-}" + if [[ -z "$AGENT_CONFIG" ]] && systemctl cat felhom-agent >/dev/null 2>&1; then + AGENT_CONFIG=$(systemctl cat felhom-agent 2>/dev/null | grep -oP '(?<=-config )\S+' | head -1) + fi + [[ -n "$AGENT_CONFIG" ]] || AGENT_CONFIG="/etc/felhom-agent/agent.json" + [[ -r "$AGENT_CONFIG" ]] || die "agent config not readable: $AGENT_CONFIG — nothing changed (is this a Felhom host? run as root)" + log_info " agent config: $AGENT_CONFIG" + # _rotate_cfg KEY — one string from the config (deployment_mode, or hub.); the path rides the + # environment, the host key goes stdout→shell var only (never argv, never printed). Exit 3 = not JSON. + _rotate_cfg() { + AGENT_CONFIG="$AGENT_CONFIG" python3 -c ' +import json, os, sys +try: + d = json.load(open(os.environ["AGENT_CONFIG"])) +except Exception: + sys.exit(3) +k = sys.argv[1] +v = d.get("deployment_mode", "") if k == "deployment_mode" else (d.get("hub") or {}).get(k, "") +print(v if isinstance(v, str) else "")' "$1" 2>/dev/null + } + ROTATE_CFG_MODE=$(_rotate_cfg deployment_mode) || die "agent config is not valid JSON: $AGENT_CONFIG — nothing changed" + HOST_ID=$(_rotate_cfg host_id) || die "agent config is not valid JSON: $AGENT_CONFIG — nothing changed" + HOST_API_KEY=$(_rotate_cfg api_key) || die "agent config is not valid JSON: $AGENT_CONFIG — nothing changed" + _rotate_hub=$(_rotate_cfg url) || die "agent config is not valid JSON: $AGENT_CONFIG — nothing changed" + [[ -n "$_rotate_hub" ]] && HUB_URL="${_rotate_hub%/}" + # Fail-safe like the agent: anything but an explicit "appliance" is treated as byo (absent/typo → byo). + if [[ "$ROTATE_CFG_MODE" != "appliance" ]]; then + die "this host's agent config says deployment_mode=${ROTATE_CFG_MODE:-}, not appliance — root@pam belongs to the host owner; nothing changed" + fi + [[ -n "$HOST_ID" && -n "$HOST_API_KEY" ]] || die "agent config has no hub.host_id/hub.api_key — cannot vault a recovery credential; nothing changed" + log_info " host_id: $HOST_ID (host key read from the agent config, not logged); hub: $HUB_URL" + # Ask the hub first: a vault that fails AFTER chpasswd leaves a password nobody holds. + _rotate_hc=$(http_code --max-time 15 "$HUB_URL/healthz" || true); _rotate_hc="${_rotate_hc: -3}" + if [[ "$_rotate_hc" != "200" ]]; then + if $DRY_RUN; then + log_warn " hub $HUB_URL/healthz answered HTTP ${_rotate_hc:-000} — a real run would stop here, before the password changes" + else + die "hub $HUB_URL/healthz answered HTTP ${_rotate_hc:-000} — the password was NOT changed (a vault after it would fail)" + fi + else + log_info " hub answers (healthz 200)" + fi + ROTATE_RECOVERY=true # the step's own "already vaulted" skip must not apply: rotating is the point + if [[ "$ROTATE_CFG_MODE" == "appliance" ]]; then + step_break_glass + fi + HOST_API_KEY="" + echo "" + if $DRY_RUN; then + log_warn "DRY-RUN: nothing above was actually executed." + else + log_success "ROTATE-RECOVERY-ONLY complete — only root@pam's password changed (and its hub vault); agent, config, root files and guests untouched." + fi + exit 0 +fi + #=============================================================================== # UNINSTALL MODE — local host teardown (no hub contact, no passphrase). Dispatched early, # before any provision/DR logic, and does not require --customer-id. @@ -2382,58 +2525,6 @@ step_enroll() { _state_mark enroll } -#------------------------------------------------------------------------------- -# STEP 4b — break-glass credential (TASK G1): generate + set + vault the root@pam console password -#------------------------------------------------------------------------------- -# The human fallback for when BOTH the sshd path AND the agent-independent auto-heal (layers 1+2) have -# failed: a strong root@pam password lets the operator reach the PVE WEB CONSOLE (pveproxy :8006 — a -# failure domain distinct from sshd) and run the one-line /run/sshd fix. Generated with strong entropy, -# set via chpasswd, and vaulted to the hub over the enroll-authenticated channel (host api_key). The -# password is NEVER logged, printed, or written to any file — it goes stdin→chpasswd and stdin→curl -# only (SPIKE-felhom-sshd finding #9 / TASK G1 trap 3). Idempotent: skipped if already vaulted unless -# --rotate-recovery (a re-set would strand the operator's saved copy). -step_break_glass() { - log_step "4b/8 break-glass credential (root@pam console password → hub vault)" - if [[ -z "${HOST_ID:-}" || -z "${HOST_API_KEY:-}" ]]; then - log_warn " no host_id/api_key (enroll skipped?) — cannot vault a recovery credential; skipping" - return 0 - fi - if $DRY_RUN; then - log_dry "openssl rand → strong root@pam password (never logged) ; chpasswd ; PUT $HUB_URL/api/v1/hosts/$HOST_ID/recovery-credential (Bearer host key)" - _state_mark break_glass; return 0 - fi - if _state_has break_glass && ! $ROTATE_RECOVERY; then - log_skip " recovery credential already vaulted (use --rotate-recovery to regenerate)" - return 0 - fi - # Strong password: 24 url-safe bytes (~144 bits). Kept ONLY in a local shell var, never on disk. - local newpw - newpw=$(openssl rand -base64 24 2>/dev/null | tr -d '\n' | tr '+/' '-_') - [[ ${#newpw} -ge 24 ]] || die "failed to generate a strong recovery password" - # Set root@pam (= the Linux root user on PVE) via chpasswd on STDIN — no argv, no log. - if ! printf 'root:%s\n' "$newpw" | chpasswd 2>/dev/null; then - newpw="" # scrub - die "chpasswd failed to set the root@pam recovery password" - fi - # Vault to the hub over the host-key-authenticated channel; password only on stdin (-d @-). - local code - code=$(printf '{"username":"root@pam","password":"%s"}' "$newpw" \ - | curl -sS -o /dev/null -w '%{http_code}' -X PUT \ - "$HUB_URL/api/v1/hosts/$HOST_ID/recovery-credential" \ - -H "Authorization: Bearer $HOST_API_KEY" -H 'Content-Type: application/json' -d @- 2>/dev/null) - newpw="" # scrub the plaintext from the shell var the moment it is vaulted - case "$code" in - 200) log_success " root@pam password set + vaulted to the hub (retrieve via the operator /admin path; never logged here)" - # Drill F-8: say this OUT LOUD — the operator was live-surprised by a 401 at the PVE - # GUI. Pointer only, never the credential. - log_warn " NOTE: the root@pam password just CHANGED — the old one now fails at the PVE web GUI (:8006)." - log_warn " Retrieve the new one at hub → host page (vaulted recovery credential)." ;; - 401|403) die "recovery-credential vault rejected ($code) — host key/authorization problem" ;; - *) die "recovery-credential vault failed (HTTP $code)" ;; - esac - _state_mark break_glass -} - #------------------------------------------------------------------------------- # STEP 5 — agent install: fetch+verify the binary, ensure the service user, sudoers, unit #------------------------------------------------------------------------------- diff --git a/scripts/hostinstall-mode-harness.sh b/scripts/hostinstall-mode-harness.sh index af5d4334..70b4e4dc 100644 --- a/scripts/hostinstall-mode-harness.sh +++ b/scripts/hostinstall-mode-harness.sh @@ -153,18 +153,22 @@ else verdict FAIL "C6 byo PVE-major gate present (static grep)" fi -# INV-1: exactly ONE step_break_glass invocation, and it is gated on MODE == appliance. -# (Comment lines and the function definition itself don't count.) +# INV-1: exactly TWO step_break_glass invocations, each appliance-gated: the install's (gated on +# MODE == appliance) and --rotate-recovery-only's (R-1141, gated on the agent config's +# deployment_mode == appliance). (Comment lines and the function definition itself don't count.) inv_calls=$(grep -n 'step_break_glass' "$SCRIPT" \ | grep -v -E '^[0-9]+:[[:space:]]*#' \ | grep -v 'step_break_glass()' || true) inv_count=$(echo "$inv_calls" | grep -c 'step_break_glass' || true) -if [[ "$inv_count" == "1" ]] \ +inv_bare=$(echo "$inv_calls" | grep -v 'should_skip break_glass' | cut -d: -f1 || true) +if [[ "$inv_count" == "2" ]] \ && echo "$inv_calls" | grep -q 'should_skip break_glass' \ - && grep -B4 'should_skip break_glass' "$SCRIPT" | grep -q 'MODE" == "appliance"'; then - verdict PASS "INV-1 break-glass call site: exactly one, appliance-gated" + && grep -B4 'should_skip break_glass' "$SCRIPT" | grep -q 'MODE" == "appliance"' \ + && [[ -n "$inv_bare" ]] \ + && sed -n "$((inv_bare-1))p" "$SCRIPT" | grep -q 'ROTATE_CFG_MODE" == "appliance"'; then + verdict PASS "INV-1 break-glass call sites: exactly two, both appliance-gated" else - verdict FAIL "INV-1 break-glass call site: exactly one, appliance-gated" "count=$inv_count; calls: $(echo "$inv_calls" | tr '\n' ' ')" + verdict FAIL "INV-1 break-glass call sites: exactly two, both appliance-gated" "count=$inv_count; calls: $(echo "$inv_calls" | tr '\n' ' ')" fi # INV-2: chpasswd is unreachable outside step_break_glass's body (non-comment occurrences only). @@ -338,6 +342,91 @@ else verdict FAIL "GL8-F1 uninstall purges the agent config dir (every copy, R-275)" fi +echo "" +echo "--- R-1141 --rotate-recovery-only (step 4b alone) ---" +# Runs anywhere: refusals die before any host access; the dry-run reads a FAKE agent config through the +# test-only FELHOM_AGENT_CONFIG override and points the hub at a closed port. A chpasswd/systemctl/pct +# PATH shim records any call — a dry run must make none of them. +RK="FAKE-HOST-KEY-r1141-never-printed" +mkdir -p "$WORK/r1141shim" +for c in chpasswd pct qm pveum systemctl apt-get install; do + printf '#!/bin/sh\necho "%s $*" >> "%s/r1141shim/calls"\nexit 1\n' "$c" "$WORK" > "$WORK/r1141shim/$c" + chmod 0755 "$WORK/r1141shim/$c" +done +r1141_cfg() { # + python3 - "$1" "$2" "$3" <<'PY' +import json, sys +f, mode, key = sys.argv[1:] +d = {"hub": {"url": "http://127.0.0.1:9", "host_id": "h-test", "api_key": key}} +if mode != "-": + d["deployment_mode"] = mode +json.dump(d, open(f, "w")) +PY + chmod 0600 "$1" +} +r1141_run() { # + local cfg="$1"; shift + set +e + out=$(FELHOM_INSTALL_STATE_DIR="$STATE_OVERRIDE_ENV" FELHOM_AGENT_CONFIG="$cfg" PATH="$WORK/r1141shim:$PATH" \ + bash "$SCRIPT" --rotate-recovery-only "$@" &1) + rc=$? + set -e +} +r1141_expect_die() { # + local name="$1" msg="$2" cfg="$3"; shift 3 + r1141_run "$cfg" "$@" + if [[ $rc -ne 0 && "$out" == *"$msg"* && "$out" != *"4b/8"* ]]; then + verdict PASS "$name" + else + verdict FAIL "$name" "rc=$rc; wanted '$msg', no 4b/8; got: $(echo "$out" | tail -3 | tr '\n' ' ')" + fi +} +r1141_cfg "$WORK/r1141-app.json" appliance "$RK" +r1141_cfg "$WORK/r1141-byo.json" byo "$RK" +r1141_cfg "$WORK/r1141-nomode.json" - "$RK" +r1141_cfg "$WORK/r1141-nokey.json" appliance "" +printf 'not json' > "$WORK/r1141-bad.json" +r1141_expect_die "R1141-a --mode byo refused" "is not allowed in byo mode" "$WORK/r1141-app.json" --mode byo --dry-run +r1141_expect_die "R1141-b with --uninstall refused" "--rotate-recovery-only runs alone" "$WORK/r1141-app.json" --uninstall --dry-run +r1141_expect_die "R1141-c with --resume refused" "--rotate-recovery-only runs alone" "$WORK/r1141-app.json" --resume --dry-run +r1141_expect_die "R1141-d config deployment_mode=byo refused" "deployment_mode=byo, not appliance" "$WORK/r1141-byo.json" --dry-run +r1141_expect_die "R1141-e config without deployment_mode refused (fail-safe)" "deployment_mode=, not appliance" "$WORK/r1141-nomode.json" --dry-run +r1141_expect_die "R1141-f config without a host key refused" "no hub.host_id/hub.api_key" "$WORK/r1141-nokey.json" --dry-run +r1141_expect_die "R1141-g config not JSON refused" "agent config is not valid JSON" "$WORK/r1141-bad.json" --dry-run +r1141_expect_die "R1141-h config missing refused" "agent config not readable" "$WORK/r1141-absent.json" --dry-run +if [[ "$(id -u)" != 0 ]]; then + r1141_expect_die "R1141-i a real run needs root" "must run as root" "$WORK/r1141-app.json" +else + verdict SKIP "R1141-i a real run needs root" "running as root — the refusal cannot be shown here" +fi +# The positive dry run: step 4b's dry line only, the host key never printed, no other step, no host +# command, no state written. +rm -f "$WORK/r1141shim/calls" "$STATE_OVERRIDE/state.json" +r1141_run "$WORK/r1141-app.json" --dry-run +r_ok=true; r_why="" +[[ $rc -eq 0 ]] || { r_ok=false; r_why+="rc=$rc "; } +for want in "mode=rotate-recovery-only" "4b/8 break-glass credential" \ + "PUT http://127.0.0.1:9/api/v1/hosts/h-test/recovery-credential" "a real run would stop here"; do + [[ "$out" == *"$want"* ]] || { r_ok=false; r_why+="missing '$want' "; } +done +for bad in "$RK" "1/8" "2/8" "3/8" "4/8" "5/8" "6/8" "7/8" "8/8" "agent install" "PASSPHRASE" "retrieval passphrase"; do + [[ "$out" != *"$bad"* ]] || { r_ok=false; r_why+="contains '$bad' "; } +done +[[ ! -s "$WORK/r1141shim/calls" ]] || { r_ok=false; r_why+="host commands called: $(tr '\n' ';' < "$WORK/r1141shim/calls") "; } +[[ ! -e "$STATE_OVERRIDE/state.json" ]] || { r_ok=false; r_why+="state.json written "; } +if $r_ok; then + verdict PASS "R1141-j dry run: step 4b only, host key not printed, no host command, no state" +else + verdict FAIL "R1141-j dry run: step 4b only, host key not printed, no host command, no state" "$r_why" +fi +# Usage documents the flag (the real -h path). +run_script -h +if [[ $rc -eq 0 && "$out" == *"--rotate-recovery-only"* ]]; then + verdict PASS "R1141-k usage documents --rotate-recovery-only" +else + verdict FAIL "R1141-k usage documents --rotate-recovery-only" "rc=$rc" +fi + echo "" echo "--- F5 appliance guest auto-sizing (VALIDATION-n100) ---" # The auto-size log line is emitted right after mode validation (BEFORE any PVE/hub contact), so it