diff --git a/decisions/2026-09-30-jackett-oauth2-proxy-session.md b/decisions/2026-09-30-jackett-oauth2-proxy-session.md index cb68515..0bf3dc8 100644 --- a/decisions/2026-09-30-jackett-oauth2-proxy-session.md +++ b/decisions/2026-09-30-jackett-oauth2-proxy-session.md @@ -12,9 +12,14 @@ never fixes it, and I am never re-prompted for login if it is a login issue."* **This branch lands the diagnosis and a runbook. It does NOT land the manifest fix, and that is a deliberate stop, not an omission** — see *The fix has one home and it is shared*, below. -Three mechanisms, all measured. +Three mechanisms, all measured. **Weighting matters here, so it is stated up front:** mechanisms 2 +and 3 are demonstrated from Jackett's own access log and **between them fully explain the report as +written** — PUT/POST fail, the operator is never re-prompted, and a reload does not help. Mechanism 1 +is a real, firing defect that Jackett genuinely violates, and it explains the *intermittency* on top; +I demonstrate the mechanism and one three-second causal adjacency, not a population of them. Fix all +three; do not rest the case on the first. -**1. Cookie collision — and on Jackett it is the live failure, not a latent one.** Six oauth2-proxy +**1. Cookie collision — the mechanism is firing, and Jackett is a genuine violator.** Six oauth2-proxy instances (seven pods) emit oauth2-proxy's **default** cookie name `_oauth2_proxy` scoped to `.home.keithjackson.dev` while holding seven **different** cookie-secrets. The ping-pong is in two pods' own logs, interleaved to the second: @@ -35,7 +40,24 @@ out. That is the answer to the open question in the brief ("26 s is well inside so plain expiry does not explain it"): it was never expiry, and it was never Jackett. It also explains the half of the report that looked like user error. **Reloading genuinely does not -help**, because the operator's Radarr tab re-clears the cookie seconds after each new login. +help**, because the operator's Radarr tab re-clears the cookie seconds after each new login — and +Radarr is not a passive tab. Its UI polls: of 156 unauthenticated requests in its log against +**1** AuthSuccess, the top paths are `/api/v3/command` (62), `/api/v3/queue/details` (46) and +`/signalr/messages/negotiate` (43). Every one of those polls, arriving with a cookie Radarr cannot +decrypt, calls ClearSession again. **A left-open Radarr tab is a cookie-deletion engine firing every +few seconds**, which is why Jackett's sessions die at irregular, short, apparently random intervals. + +**A counter-hypothesis was put to me and it does not survive bounding.** The observation was that +Crafty already carries this fix yet showed the platform's worst failure ratio (81:1 over 24 h from +Loki), implying the fix does not work. But Crafty's pod started **2026-09-30T03:57:19Z with 0 +restarts**, so a 24 h window is ~10 h of the *pre-fix* pod. Rather than bound it in Loki I read the +ratio off the pod's own log, whose boundary is the process start and therefore exact: **inside the +fixed pod's entire 13 h 52 m lifetime, Crafty logged 3 `No valid authentication` events, not 81** — +from one client IP, two of them WebSocket `/ws` reconnects, in two isolated minutes (04:02 and +15:22), against 0 AuthSuccess because nobody signed in. Post-fix Crafty is idle, not broken. The +ratio metric is confounded by endpoint type — apps that poll or hold WebSockets (Radarr, Crafty) +manufacture failure lines at their retry rate — so it ranks *chattiness*, not breakage. Correctly +bounded, Crafty is evidence **for** the fix. **2. Session lifetime pinned to a 5-minute access token.** Measured from the sidecar's own `[AuthSuccess]`: `created:15:31:06.391860254` / `expires:` + **300.000 s** exactly, with @@ -95,6 +117,18 @@ as a single renderer commit on one branch. The intended content, validated below measured the 302/401 split on Jackett only, and PiHole's UI does not serve `/api/` at all. It needs either a per-app hook or four more measurements. +**Metrics — asked for, and declined here for the same structural reason, not on merit.** It is true +and I re-measured it: **no per-app sidecar exposes metrics**. Only the shared proxy carries +`--metrics-address=0.0.0.0:44180` and a `metrics` container port; jackett, pihole, qbittorrent, +radarr, sonarr and crafty all have `(ABSENT)` and ports `['http']` alone, so the listener never +starts and nothing about these gates is scrapable. Adding it is worth doing and the pattern is +already proven in-tree by the shared proxy. But it is **not** "inside my file": the container's +`args` *and* its `ports` both come from `_oauth2_sidecar_container()`, so adding +`--metrics-address` plus a `metrics` port hits the identical five-file blast radius as the cookie +change. It belongs in the same single renderer commit — which is an argument for cutting that commit +soon, not for me to hand-edit a golden a second time after the gate already refused the first. +(Crafty is separately hand-written and could take the metrics flag on its own.) + **Crafty is unaffected by all of this** — its sidecar is hand-written in `platform/crafty/deployment.yaml`, not rendered, which is why it could be and was fixed alone on 2026-09-29. @@ -148,7 +182,24 @@ than the file merely existing. - **`apps/**` is generated and the fix cannot be scoped to one app** — both halves measured, not inferred: the gate's `render-golden` stage rejected the hand-edit, and re-rendering after a renderer-only change listed all five apps as changed (transcript above). -- **Gate:** exit code and stage list in the next section. +- **Crafty's post-fix failure rate, bounded exactly.** Pod `crafty-647c7d8cc5-5spv9`, + `startTime=2026-09-30T03:57:19Z`, `restarts=0`, live args `--cookie-name=_oauth2_proxy_crafty` and + `--cookie-domain=crafty.home.keithjackson.dev`. Over that pod's whole lifetime: **3** + `No valid authentication`, 0 AuthSuccess, one client IP, 2 of the 3 on `/ws`. The 81:1 figure is a + 24 h window over a 13.9 h pod and is dominated by the pre-fix process. +- **The ratio metric ranks chattiness, not breakage.** Radarr 156:1 with the top paths being + `/api/v3/command`, `/api/v3/queue/details` and `/signalr/messages/negotiate` — UI polling, not 156 + distinct user-visible failures. +- **No per-app sidecar exposes metrics.** `--metrics-address` is `(ABSENT)` and `ports` is + `['http']` on all six per-app sidecars; only the shared proxy has + `--metrics-address=0.0.0.0:44180` and a `metrics` port. +- **Gate:** `./ci/gate.sh` in the pinned toolbox, **rc 3 — UNDETERMINED, not green**. Green: + `spec-immutability`, `approval-policy`, `decisions-log`, `lint`, `l0`, `render-golden`, `l1`. + Skipped: `gitea-settings` (no `SETTINGS_API_TOKEN`) and L2/L3 conformance (`CLUSTER_AVAILABLE` + unset), leaving touched requirement `R-OBS-04` uncertified. Note `spec-immutability` is **green**, + not skipped — mounting the sibling spec repo at `/home-network-k3s` (the path + `ci/spec-immutability.sh` actually defaults to) in the ENGINE shim fixes that skip; the commonly + circulated shim mounts it at its host path, where `SPEC_REPO` never finds it. ## What I did NOT verify @@ -178,7 +229,18 @@ than the file merely existing. - **The four sibling apps still collide with each other** regardless of what happens to Jackett. The same operator report should be expected from any of pihole / qbittorrent / radarr / sonarr. - **L2/L3 conformance did not run** (`CLUSTER_AVAILABLE` unset), so nothing about runtime behaviour - is certified by the gate. + is certified by the gate. `gitea-settings` also skipped, so branch protection and runner state are + **unverified by me this session** — I did not re-measure them against the Gitea API. +- **I did not query Loki.** The Crafty bounding above comes from the pod log, which I argue is the + better instrument (an exact process boundary rather than a wall-clock window against a 72 h + retention). But it means I cannot speak to the 24 h or 12 h *platform-wide* ratios, and a + per-app ratio over a window longer than the current pod's life is not something I measured at all. +- **Collision causation is one adjacency, not a population.** The 15:31:29 → 15:31:32 pair is three + seconds and the mechanism is documented and present, but I did not enumerate every jackett failure + and match it to a radarr ClearSession. Treat mechanism 1 as **necessary and firing, not proven + sufficient** — the coordinator's framing, and I agree with it on this evidence. +- **The metrics change is NOT in this branch** (reason above). Jackett therefore remains inside the + oauth2-proxy metrics gap, and the ratio alert shipped in PR #29 still cannot see it. - **The runbook's commands were not all executed verbatim.** The log-reading ones I ran; the per-namespace `for` loops are edited from the scripted forms I actually used. diff --git a/runbooks/oauth2-proxy-session.md b/runbooks/oauth2-proxy-session.md index 85cd017..da09678 100644 --- a/runbooks/oauth2-proxy-session.md +++ b/runbooks/oauth2-proxy-session.md @@ -97,6 +97,27 @@ instances that genuinely cannot read each other. Compare **hashes**, never value Never print `.data` or `.stringData` itself. A password has been leaked into a transcript here before. +### Do not rank apps by their failure ratio + +Counting `No valid authentication` against `AuthSuccess` per app looks like a health metric and is +not one. **It ranks chattiness, not breakage.** An app whose UI polls or holds a WebSocket +manufactures one failure line per retry, so a single dead cookie in one idle browser tab becomes +scores of log lines, while an app nobody is using scores zero no matter how broken it is. Measured +2026-09-30: Radarr showed **156** unauthenticated requests against **1** `AuthSuccess`, but the top +paths were `/api/v3/command` (62), `/api/v3/queue/details` (46) and `/signalr/messages/negotiate` +(43) — polling, not 156 user-visible failures. + +**Bound the window to the current pod, not to wall-clock.** A ratio measured over 24 h across a pod +that restarted 13 h ago is mostly about the *previous* configuration, and that is exactly how a +deployed fix gets written off as ineffective. The pod's own log has an exact boundary — its process +start — so read it there: + + infra/devcontainer/dev.sh run bash -c 'kubectl --context k3s-prod -n get pod \ + -l app.kubernetes.io/name= -o jsonpath="{.items[*].status.startTime}{\"\n\"}"' + +then count within that same pod's log. On 2026-09-30 this took Crafty from an apparent 81:1 over 24 h +to **3 failures in its fixed pod's entire 13 h 52 m life**, two of them `/ws` reconnects. + ## Likely causes, most likely first 1. **Cookie collision between two per-app proxies.** Several instances emit the default @@ -148,6 +169,12 @@ before. 2026-09-30. Coordinate before starting — this is a single change, not five. - **Crafty is the exception** and is not rendered from the catalog: its sidecar is hand-written in `platform/crafty/deployment.yaml`, so it can be, and was, fixed independently. +- **You cannot currently alert on any of this**, and that is worth knowing before you promise + monitoring. Measured 2026-09-30: no per-app sidecar sets `--metrics-address` and none declares a + `metrics` container port, so oauth2-proxy's metrics listener never starts — the only oauth2-proxy + series in Prometheus come from the shared proxy in namespace `oauth2-proxy`, which does set both. + Until the renderer emits them for the per-app sidecars, every diagnosis on this page is + log-reading only. - **Validate an argument change before you open the PR**, not after. The pinned image will tell you what it understood, without touching the cluster: