fix(security): hard per-fetch timeout + per-step timing on password login - #362
Merged
Merged
Conversation
…ogin Password login hung 60s+ and timed out: the fetch() calls driving the Authentik flow-executor and the OIDC authorize->code redirect chain had NO timeout, so any stuck hop (notably the authorize hairpin out to app.fuzefront.com via Cloudflare) hung the whole request forever with no further server log until the client gave up. - Add fetchWithTimeout() (AbortController, AUTHENTIK_FLOW_TIMEOUT_MS, default 10s) to EVERY fetch in authentikPassword.ts (flowRequest, completeOidcWithSession, authentikSetPassword). A stuck hop now fails fast with a labelled AuthentikUnavailableError instead of hanging. - Add per-step timing logs (flow.step, authorize.hop, oidc.token, oidc.userinfo, user.sync with elapsed ms) so the exact blocking step is visible in prod logs. - oidc.ts handleCallback already honours custom.setHttpOptionsDefaults timeout; now times token/userinfo/sync individually. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session-Id: f636c22e-1cd7-401e-8843-97e3e3a4ba01
Contributor
Automated code review (gate-code-review)Credit balance is too low Report-only — this check never blocks merge. |
2 tasks
izzywdev
added a commit
that referenced
this pull request
Jul 23, 2026
* fix(security): route brokered OIDC authorize hop internally + add structured logging Task 1: completeOidcWithSession's authorize fetch hairpinned out through Cloudflare/ingress to the EXTERNAL authorize URL (~6.5s per prod timing logs) instead of the internal Authentik service DNS oidc.ts already uses for token/userinfo/jwks. toInternalAuthorizeUrl() rewrites protocol+host only (redirect_uri/state/PKCE unchanged) so token validation is unaffected. Expected ~6.5s -> ~0.2s on that hop. Task 2: add a shared pino logger (src/lib/logger.ts) with LOG_LEVEL control and mandatory credential/token/cookie redaction, and instrument the previously-silent auth-critical paths (authentikPassword, oidc, googleOidc, brokerCodes, api-token, organizationProvisioning, authz.ts) with boundary start/end + elapsed-ms + decision-branch + error-context logging. Converts PR #362's temporary console.log timing lines to leveled logger calls. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session-Id: f636c22e-1cd7-401e-8843-97e3e3a4ba01 * fix(ci): sync package-lock.json after adding pino to backend/security pino@^9.5.0 was added to backend/security/package.json but the root package-lock.json was not updated, causing npm ci to fail with a lock-file/package.json mismatch. Ran npm install --package-lock-only to resolve pino@9.14.0 into backend/node_modules/pino and record it in the workspace dependencies section. Fixes failing CI on PR #366. Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com> --------- Co-authored-by: fuzeone-bot[bot] <fuzeone-bot[bot]@users.noreply.github.com> Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com> Co-authored-by: claude[bot] <41898282+claude[bot]@users.noreply.github.com>
42 tasks
izzywdev
pushed a commit
that referenced
this pull request
Jul 29, 2026
Task 3 of the sign-in investigation: find the slowness. The blocker was that the evidence has never existed when it mattered. Per-hop timings were already instrumented — at `logger.debug`. LOG_LEVEL defaults to `info` and is not set anywhere in the chart, so in production that detail has always been OFF. Answering "which hop is slow?" needed a config change or a redeploy, during an incident, on a path that only misbehaves intermittently. That is why this module has collected two timeout band-aids (#362, #371) and no diagnosis. Adds a slow-hop threshold (the slow-query-log pattern): every hop is still debug on the fast path, but a hop over AUTHENTIK_SLOW_HOP_WARN_MS (1s) is logged at WARN with its stage label, status and elapsed time. No LOG_LEVEL change, no redeploy, no spam on healthy logins. The token-exchange stage is now timed the same way — it is two openid-client round-trips and just as able to be the slow one, so it must not be the one stage missing from the breakdown. Also reports a slow SUCCESS. A login that succeeds at 25s is exactly the failure mode that broke sign-in: it never errors, so nothing alerts, and it only became visible once a client bound tripped underneath it. Over AUTHENTIK_LOGIN_WARN_MS (8s, above the ~5.5s fast path) that now logs at WARN, and the per-hop WARNs say which stage owned the time. Leading hypothesis, written into the code so the logs can refute it rather than confirm a guess: every hop targets the same in-cluster origin, and this pod's own dnsConfig documents CoreDNS "intermittently stalls lookups in 5s/10s retry multiples" (capped ~2s by timeout:1/ attempts:2) with the note that this service "resolves authentik-server on every auth flow". DNS resolves per NEW CONNECTION, and the leaked response bodies fixed earlier in this PR forced a new connection per hop — so the stall was multiplied by hop count. ~6 hops x ~2s accounts for most of the observed 16-30s, and draining bodies lets undici reuse one keep-alive socket per origin, collapsing it to at most one. If the labelled elapsedMs still shows connect/DNS dominating, the next step is an explicit keep-alive dispatcher pinned to the Authentik origin. This is instrumentation, not a proven cure: it is what turns the next slow sign-in into a named stage instead of another guess. Tests: 1 new case — a slow hop on a login that SUCCEEDS emits exactly one WARN carrying the stage label and elapsed time. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QhfKNASYBD9aS3Wu6RUPfZ
izzywdev
pushed a commit
that referenced
this pull request
Aug 2, 2026
…ver-side login Every hop in the server-brokered password-login chain (flow-executor stages, authorize hops, admin-API set_password) lands on the same in-cluster Authentik origin, several times per request. The default fetch dispatcher's keep-alive window is tuned for general traffic and can lapse between hops when CoreDNS's documented multi-second stalls (see the recordHop comments in authentikPassword.ts) space them out, forcing a fresh connection — and a fresh DNS lookup — per hop. A dedicated undici Agent with a longer keep-alive holds one socket open across the whole chain, so only the first hop pays for DNS+connect. This was the last documented, unapplied mitigation in that file's own incident notes (#362, #371) for the intermittent 16-30s+ sign-in stalls that show up as an outright client-side timeout for some accounts.
izzywdev
added a commit
that referenced
this pull request
Aug 2, 2026
…ver-side login (#494) Every hop in the server-brokered password-login chain (flow-executor stages, authorize hops, admin-API set_password) lands on the same in-cluster Authentik origin, several times per request. The default fetch dispatcher's keep-alive window is tuned for general traffic and can lapse between hops when CoreDNS's documented multi-second stalls (see the recordHop comments in authentikPassword.ts) space them out, forcing a fresh connection — and a fresh DNS lookup — per hop. A dedicated undici Agent with a longer keep-alive holds one socket open across the whole chain, so only the first hop pays for DNS+connect. This was the last documented, unapplied mitigation in that file's own incident notes (#362, #371) for the intermittent 16-30s+ sign-in stalls that show up as an outright client-side timeout for some accounts. Co-authored-by: Claude <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
URGENT prod: password login hangs 60s+ and times out
Root cause
Authentik authenticates the password flow fast (~1.5s). The hang is server-side in the FuzeFront security service's OIDC completion after Authentik auth succeeds: the
fetch()calls inauthentikPassword.ts(flow-executor driver + the OIDC authorize→code redirect chain, notably the authorize hairpin out toapp.fuzefront.comvia Cloudflare) had no timeout, so a stuck hop hung the whole request until the client's ~60s timeout — with no further server log.Change (backend slice)
fetchWithTimeout()(AbortController,AUTHENTIK_FLOW_TIMEOUT_MS, default 10s) on everyfetchinauthentikPassword.ts(flowRequest,completeOidcWithSession,authentikSetPassword). A stuck hop now fails fast with a labelledAuthentikUnavailableError.flow.step,authorize.hop,oidc.token,oidc.userinfo,user.sync(elapsed ms) to pinpoint the blocking step in prod.oidc.ts handleCallbackalready honourscustom.setHttpOptionsDefaults({ timeout })(OIDC_HTTP_TIMEOUT_MS, 15s); now times token/userinfo/sync individually.Verification
tsc --noEmit: clean for edited files.POST /api/v1/security/session< 3s.🤖 Generated with Claude Code