From f1eabd88850fea3985e098846bec2e0ce314ffb1 Mon Sep 17 00:00:00 2001 From: Diego Rodrigues de Sa e Souza Date: Fri, 18 Sep 2026 11:57:51 -0300 Subject: [PATCH] fix(sse): stop direct fetch retry reusing pooled flat response-start budget (#13703) (#14047) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit resolveDirectHeadersTimeoutMs() (open-sse/utils/directResponseStartTimeout.ts) now bounds only the pooled dispatcher attempt (attempt 0) with the flat OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS watchdog. The fresh-socket retry (attempt 1) is by construction a brand-new socket with no zombie-socket risk (#10214's rationale only applies to the pooled attempt), so when the caller already attached its own deadline signal it now defers to a generous, configurable backstop (OMNIROUTE_DIRECT_RESPONSE_RETRY_TIMEOUT_MS, default 600s) instead of reusing the identical short flat window — fixing spurious 504s on healthy slow-TTFB reasoning models that need well over 60s total for both attempts. Regression test: tests/unit/proxyfetch-direct-response-start-flat-retry-budget-13703.test.ts (RED against unmodified code: retry cut at 81ms against an 80ms flat budget with ~1920ms of caller deadline unused; GREEN after the fix). New env var documented in .env.example and docs/reference/ENVIRONMENT.md. tlsProfileForProvider's return type in proxyFetch.ts is pulled into a named alias so its signature stays on one line under prettier's canonical formatting -- otherwise prettier's mandatory lint-staged reformat of this frozen file grows it past the check:file-size baseline on every future touch. base-red inherited: #14004 (docs env/docs contract, fixed separately in #14022; chatHelpers file-size drift) --- .env.example | 12 +++ ...direct-response-start-retry-flat-budget.md | 1 + docs/reference/ENVIRONMENT.md | 1 + open-sse/utils/directResponseStartTimeout.ts | 59 ++++++++++++-- open-sse/utils/proxyFetch.ts | 7 +- ...onse-start-flat-retry-budget-13703.test.ts | 81 +++++++++++++++++++ 6 files changed, 152 insertions(+), 9 deletions(-) create mode 100644 changelog.d/fixes/13703-direct-response-start-retry-flat-budget.md create mode 100644 tests/unit/proxyfetch-direct-response-start-flat-retry-budget-13703.test.ts diff --git a/.env.example b/.env.example index d2cd8d7d7b..6cb7323fbe 100644 --- a/.env.example +++ b/.env.example @@ -1548,6 +1548,18 @@ CURSOR_USER_AGENT="Cursor/3.4" # # caller's deadline; on expiry the request retries # # once on a fresh no-keep-alive socket. 0 disables # # the bound (default: 30000 = 30s). +# OMNIROUTE_DIRECT_RESPONSE_RETRY_TIMEOUT_MS=600000 # Ceiling (ms) for the fresh-socket +# # RETRY attempt above (#13703). Only applies when +# # the caller already attached its own deadline +# # signal (the resolved connection/model/provider/ +# # FETCH_TIMEOUT_MS cascade) — that signal is the +# # real bound and fires first in the intended path, +# # so this is a generous backstop rather than a flat +# # cap: without it the retry reused the same short +# # OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS window as the +# # pooled attempt and 504'd healthy slow-TTFB +# # reasoning models. Never allowed below the flat +# # floor above (default: 600000 = 10 min). # Default timeout (ms) for src/shared/utils/fetchTimeout.ts. Acts as the # fallback when FETCH_TIMEOUT_MS is unset. Default: 120000 (2 min). diff --git a/changelog.d/fixes/13703-direct-response-start-retry-flat-budget.md b/changelog.d/fixes/13703-direct-response-start-retry-flat-budget.md new file mode 100644 index 0000000000..773b7dcda8 --- /dev/null +++ b/changelog.d/fixes/13703-direct-response-start-retry-flat-budget.md @@ -0,0 +1 @@ +- fix(sse): stop the direct (no-proxy) fresh-socket retry from reusing the pooled attempt's flat `OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS` response-start watchdog — the retry is a brand-new socket with no zombie to detect (#10214's rationale only applies to the pooled attempt), so when the caller already attached its own deadline signal (the resolved connection/model/provider/`FETCH_TIMEOUT_MS` cascade) the retry now defers to a generous, `OMNIROUTE_DIRECT_RESPONSE_RETRY_TIMEOUT_MS`-configurable backstop instead of an identical short flat window, fixing spurious 504s on healthy slow-TTFB reasoning models (#13703) diff --git a/docs/reference/ENVIRONMENT.md b/docs/reference/ENVIRONMENT.md index 7906d8712a..10cbf532a6 100644 --- a/docs/reference/ENVIRONMENT.md +++ b/docs/reference/ENVIRONMENT.md @@ -779,6 +779,7 @@ REQUEST_TIMEOUT_MS (global override) | `OMNIROUTE_CODEX_APPSERVER_AUTO_APPROVE` | `false` | Auto-approve the app-server's own approval prompts (command/file/permission execution on the host). Off by default — prompts are auto-denied; harness tool calls are unaffected (they travel the separate `item/tool/call` passthrough). Accepts `true`/`1`/`yes`. Per-connection override: `providerSpecificData.codexAppServerAutoApprove`. | | `FETCH_HEADERS_TIMEOUT_MS` | = `FETCH_TIMEOUT_MS` | Time to receive response headers. | | `OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS` | `30000` (30s) | Maximum response-start wait (ms) for each direct no-proxy attempt. A timeout retries once on a fresh socket; set `0` to disable the bound and retain the previous behavior. | +| `OMNIROUTE_DIRECT_RESPONSE_RETRY_TIMEOUT_MS` | `600000` (10 min) | Ceiling (ms) for the fresh-socket RETRY attempt after a pooled-attempt response-start timeout above (#13703). Applies only when the caller already attached its own deadline signal (the resolved connection/model/provider/`FETCH_TIMEOUT_MS` cascade); that signal is the real bound and fires first in the intended path, so this is a generous backstop rather than a flat cap — without it, the retry reused the identical short `OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS` window as the pooled attempt and 504'd healthy slow-TTFB reasoning models. Never allowed below the flat floor above; when the caller supplies no deadline signal at all, the retry keeps the flat floor unchanged. | | `FETCH_BODY_TIMEOUT_MS` | = `FETCH_TIMEOUT_MS` | Time to receive the full response body. | | `FETCH_CONNECT_TIMEOUT_MS` | `30000` | TCP connection establishment timeout. | | `FETCH_KEEPALIVE_TIMEOUT_MS` | `4000` | Keep-alive socket idle timeout. | diff --git a/open-sse/utils/directResponseStartTimeout.ts b/open-sse/utils/directResponseStartTimeout.ts index 7325183c02..4cd71ac84d 100644 --- a/open-sse/utils/directResponseStartTimeout.ts +++ b/open-sse/utils/directResponseStartTimeout.ts @@ -4,6 +4,13 @@ type DirectFetch = (input: RequestInfo | URL, options: DirectFetchOptions) => Pr const DEFAULT_DIRECT_HEADERS_TIMEOUT_MS = 30_000; const DIRECT_RESPONSE_START_TIMEOUT_CODE = "DIRECT_RESPONSE_START_TIMEOUT"; +// #13703 — the fresh-socket RETRY (2nd direct attempt) reused the pooled +// attempt's short flat watchdog and 504'd healthy slow-TTFB upstreams: unlike +// the pooled attempt (a possibly-dead keep-alive socket, #10214), the retry is +// a brand-new socket with nothing to detect, so it defers to the caller's own +// (larger) deadline signal when one is present — see resolveDirectRetryTimeoutMs. +const DEFAULT_DIRECT_RETRY_CEILING_MS = 600_000; + // Reasoning models (GLM-5.2/5.3 reasoning.effort=high/max, codex-gpt-5.x-high, // third-party Claude-format replicas) warm up with a ~78s+ TTFB before emitting // the first byte. The stream-readiness layer (streamReadinessPolicy.ts) already @@ -23,9 +30,14 @@ function hasHighReasoningEffort(body?: string | null): boolean { return HIGH_REASONING_EFFORT_PATTERN.test(body); } +// #13703: `attempt` 0 is the pooled dispatcher (flat floor, #10214's +// zombie-socket rationale); attempt 1+ is the fresh-socket retry, which has +// no zombie to detect and so defers to resolveDirectRetryTimeoutMs instead. export function resolveDirectHeadersTimeoutMs( env: Record = process.env, - body?: string | null + body?: string | null, + attempt = 0, + hasCallerDeadline = false ): number { const raw = env.OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS; const base = @@ -36,10 +48,47 @@ export function resolveDirectHeadersTimeoutMs( : 0; // Operator override is a FLOOR: reasoning awareness only raises the budget, // never lowers it. An override above the ceiling (e.g. 240s) is preserved. - if (hasHighReasoningEffort(body)) { - return Math.max(base, REASONING_READINESS_CEILING_MS); - } - return base; + const flatFloorMs = hasHighReasoningEffort(body) + ? Math.max(base, REASONING_READINESS_CEILING_MS) + : base; + if (attempt === 0) return flatFloorMs; + return resolveDirectRetryTimeoutMs(flatFloorMs, hasCallerDeadline, env); +} + +/** + * Resolves the fresh-socket RETRY attempt's response-start ceiling (#13703). + * + * `hasCallerDeadline` is true when the caller already attached its own + * AbortSignal to the request (in production, the resolved connection -> + * model -> provider -> FETCH_TIMEOUT_MS cascade, merged in by the executor + * layer before proxyFetch ever sees the request). In that case the caller's + * own signal is the REAL deadline and always fires first in the intended + * path, so the retry gets a generous backstop ceiling + * (OMNIROUTE_DIRECT_RESPONSE_RETRY_TIMEOUT_MS, default 600s) instead of + * reusing the short flat pooled-attempt floor. + * + * When there is no caller-supplied deadline at all, there is no larger budget + * to defer to, so the retry keeps the SAME flat floor as the pooled attempt + * (`flatFloorMs`) — preserving #10214's original zombie-socket-detection + * behavior for callers that never pass their own signal. + */ +export function resolveDirectRetryTimeoutMs( + flatFloorMs: number, + hasCallerDeadline: boolean, + env: Record = process.env +): number { + if (!hasCallerDeadline) return flatFloorMs; + const raw = env.OMNIROUTE_DIRECT_RESPONSE_RETRY_TIMEOUT_MS; + const ceiling = + raw == null || raw.trim() === "" + ? DEFAULT_DIRECT_RETRY_CEILING_MS + : Number.isFinite(Number(raw)) && Number(raw) > 0 + ? Math.floor(Number(raw)) + : DEFAULT_DIRECT_RETRY_CEILING_MS; + // The env var is a ceiling operators can tune down; it must never be + // allowed to undercut the flat floor (that would re-introduce the original + // #10214 zombie-socket-detection gap on the retry attempt). + return Math.max(flatFloorMs, ceiling); } function createDirectResponseStartTimeout(timeoutMs: number): Error & { code: string } { diff --git a/open-sse/utils/proxyFetch.ts b/open-sse/utils/proxyFetch.ts index f5aafed3c7..d14cca17df 100644 --- a/open-sse/utils/proxyFetch.ts +++ b/open-sse/utils/proxyFetch.ts @@ -110,9 +110,8 @@ const TLS_PROVIDER_PROFILE: Record = { maxai: { browser: "firefox_150", os: "windows" }, }; -function tlsProfileForProvider( - provider: string | null | undefined -): { browserProfile?: string; os?: string } { +type TlsProfileResult = { browserProfile?: string; os?: string }; +function tlsProfileForProvider(provider: string | null | undefined): TlsProfileResult { if (!provider) return {}; const p = TLS_PROVIDER_PROFILE[provider.trim().toLowerCase()]; return p ? { browserProfile: p.browser, os: p.os } : {}; @@ -865,7 +864,7 @@ async function patchedFetchUnrecorded( dispatcher: attempt === 0 ? getDefaultDispatcher() : getRetryDispatcher(), }, _undiciDirect, - directHeadersTimeoutMs + resolveDirectHeadersTimeoutMs(undefined, directBodyForTimeout, attempt, !!options.signal) ); } catch (dispatcherError) { if (isDirectResponseStartTimeout(dispatcherError)) { diff --git a/tests/unit/proxyfetch-direct-response-start-flat-retry-budget-13703.test.ts b/tests/unit/proxyfetch-direct-response-start-flat-retry-budget-13703.test.ts new file mode 100644 index 0000000000..12a40c801b --- /dev/null +++ b/tests/unit/proxyfetch-direct-response-start-flat-retry-budget-13703.test.ts @@ -0,0 +1,81 @@ +// #13703 — the fresh-socket retry on a direct response-start timeout reuses +// the SAME flat `directHeadersTimeoutMs` budget as the pooled attempt instead +// of the remaining request/target budget. #10214's zombie-socket rationale +// only justifies a bound on the pooled attempt (detecting a silently-dead +// keep-alive socket); the retry is by construction a brand-new socket with no +// zombie to detect, so it should get the REMAINING budget of a much longer +// target timeout (e.g. a combo's 120s), not another flat 30s (2x the flat +// budget total, provider/model-independent). +// +// This probe proves the two attempts are bound by an IDENTICAL fixed timeout +// regardless of any larger caller-side deadline, by measuring the wall-clock +// gap between when each attempt's fetch is invoked and when it is aborted. +import { test } from "node:test"; +import assert from "node:assert/strict"; +import { proxyFetch } from "../../open-sse/utils/proxyFetch.ts"; + +function withFastTimeout(ms: number, fn: () => Promise): Promise { + process.env.OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS = String(ms); + return fn().finally(() => { + delete process.env.OMNIROUTE_DIRECT_HEADERS_TIMEOUT_MS; + }); +} + +test("#13703 fresh-socket retry gets the SAME flat budget as the pooled attempt, not the remaining target budget", async () => { + const FLAT_TIMEOUT_MS = 80; + const LARGER_CALLER_DEADLINE_MS = 2_000; + const callerDeadlineSignal = AbortSignal.timeout(LARGER_CALLER_DEADLINE_MS); + + const attemptStarts: number[] = []; + const attemptAbortedAfter: number[] = []; + + const mockUndici = (_input: RequestInfo | URL, init?: RequestInit): Promise => { + const start = Date.now(); + attemptStarts.push(start); + return new Promise((_, reject) => { + init?.signal?.addEventListener( + "abort", + () => { + attemptAbortedAfter.push(Date.now() - start); + reject( + init.signal!.reason instanceof Error + ? init.signal!.reason + : new Error(String(init.signal!.reason)) + ); + }, + { once: true } + ); + }); + }; + const mockNative = async (): Promise => + new Response("native-should-not-fire", { status: 200 }); + + await assert.rejects( + withFastTimeout(FLAT_TIMEOUT_MS, () => + proxyFetch( + "https://slow-ttfb.example/v1/chat/completions", + { method: "POST", signal: callerDeadlineSignal }, + { undiciFetch: mockUndici, nativeFetch: mockNative } + ) + ) + ); + + assert.equal(attemptStarts.length, 2, "pooled attempt + fresh-socket retry must both fire"); + + const [firstAttemptDuration, secondAttemptDuration] = attemptAbortedAfter; + const tolerance = 40; + + assert.ok( + Math.abs(firstAttemptDuration - FLAT_TIMEOUT_MS) < tolerance, + `pooled attempt should be cut at the flat ${FLAT_TIMEOUT_MS}ms budget, was cut after ${firstAttemptDuration}ms` + ); + + assert.ok( + secondAttemptDuration > FLAT_TIMEOUT_MS * 2, + `EXPECTED (fixed) behavior: fresh-socket retry should use the remaining caller ` + + `budget (~${LARGER_CALLER_DEADLINE_MS - FLAT_TIMEOUT_MS}ms available), not the ` + + `identical flat ${FLAT_TIMEOUT_MS}ms window. Got ${secondAttemptDuration}ms — ` + + `proves the retry reuses the same flat budget as the pooled attempt instead of ` + + `deriving from the timeout cascade / remaining target timeout.` + ); +});