diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index d90af07..b09b082 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -26,3 +26,24 @@ jobs: - run: pnpm test:coverage # Bundle from the committed OpenAPI snapshot (deterministic, no network). - run: pnpm build:bundle + + # The HTTP layer hands an npm `undici` dispatcher to Node's bundled fetch (a different undici + # major inside Node 22). That contract is exactly what a Node major bump can break, so also run + # the suite on the newest supported major. Kept as a separate job so the required check name + # of the primary job stays stable. + compat: + name: Node 24 compatibility + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v4 + - uses: pnpm/action-setup@v4 + - uses: actions/setup-node@v4 + with: + node-version: "24" + cache: pnpm + - run: pnpm install --frozen-lockfile + env: + ASKNEWS_NO_AGENT_SKILLS: "1" + - run: pnpm typecheck + - run: pnpm test + - run: pnpm build:bundle diff --git a/docs/architecture/overview.md b/docs/architecture/overview.md index a8c0566..a4ee47a 100644 --- a/docs/architecture/overview.md +++ b/docs/architecture/overview.md @@ -27,3 +27,30 @@ OpenAPI query parameters and request-body properties share one option generator. exclude only fields replaced by intentional positional arguments or aliases, and contract tests prove the remaining schema fields are exposed. SSE responses are decoded incrementally. Human streaming writes text deltas immediately; JSONL streaming emits complete event objects. + +## Request timeouts + +The default request timeout is 60,000 ms, or 900,000 ms (15 minutes) for DeepNews research. +`--timeout` takes precedence over `ASKNEWS_TIMEOUT_MS`; either explicit setting overrides the +operation default, including shorter or longer research budgets. + +- **Buffered responses:** one deadline per HTTP attempt covers waiting for headers and reading + the entire body. Body chunks do not restart this deadline. The transport's headers timeout and + body **inactivity** timeout are also set to the effective budget; body inactivity alone is not + a total-duration limit. There is no separate five-minute headers/body cap. +- **SSE responses:** the same effective timeout bounds the initial wait and inactivity between + received chunks, including comment-only heartbeats. Activity resets the idle timer, so a healthy + stream can outlive the timeout. A non-SSE fallback is buffered under the existing idle signal. +- **Transport:** a request-scoped Undici dispatcher interceptor sets finite request-level + headers/body timers after native fetch supplies its options, avoiding dependence on whether a + Node version supplies request-level values that override Agent defaults. Connection protections + remain at Undici defaults. No process-wide timeout is reconfigured. +- **Retries and cleanup:** network timeouts do not trigger retries. The existing single OAuth + refresh retry after a 401 remains; its buffered retry gets a fresh per-attempt budget, and token + refresh has its own timeout. Thus this is not one wall-clock cap across authentication and + multiple attempts. An unused 401 body is cancelled before retrying. Request timers, SSE readers, + and the scoped dispatcher's connections are cleaned up on success and failure. + +Timeouts and transport failures remain network errors (exit 4), distinct from API refusals +(exit 5 for 4xx, exit 6 for 5xx). A timeout cannot establish whether the server continued work; +retrying an expensive operation manually may incur another charge. diff --git a/docs/runbooks/development.md b/docs/runbooks/development.md index 2c38e6d..297de6d 100644 --- a/docs/runbooks/development.md +++ b/docs/runbooks/development.md @@ -17,5 +17,24 @@ Package installation writes the embedded skill under detected agent directories. home explicitly. Package managers may sanitize lifecycle environments; for a controlled package install use `npm_config_asknews_agent_home=/controlled/home`. +## Local timeout regression checks + +`pnpm check` includes deterministic loopback HTTP tests for dispatched timeout values, total +buffered deadlines, body stalls, SSE heartbeat/idle handling, error types, and cleanup. These +short tests do not claim to wait through the actual five-minute transport boundary. + +For the optional real wall-clock proof (about 305 seconds, loopback only, no credentials or +billable API calls), allow at least 360 seconds in your outer process runner: + +```bash +ASKNEWS_LOCAL_TIMEOUT_SMOKE=1 pnpm exec vitest run test/integration/http-timeout.integration.test.ts -t wall-clock +``` + +The smoke compares native fetch with default transport timers (300 seconds) +against the CLI's request-scoped dispatcher for both delayed headers and a delayed body. It prints +runtime versions and measured elapsed times. The fixed calls retain the default 900-second +research budget. Use `pnpm build:bundle` for a local build from the committed schema without +refreshing generated API contracts. + See [Schema refresh](schema-refresh.md) for generated-contract review and [Private release preparation](release.md) for package verification and approval boundaries. diff --git a/package.json b/package.json index aeab459..86eb0d0 100644 --- a/package.json +++ b/package.json @@ -62,6 +62,7 @@ "cli-table3": "0.6.5", "commander": "14.0.3", "terminal-link": "^5.0.0", + "undici": "7.29.1", "yaml": "2.8.3", "zod": "3.25.76" }, diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index 4379c38..00c96b7 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -23,6 +23,9 @@ importers: terminal-link: specifier: ^5.0.0 version: 5.0.0 + undici: + specifier: 7.29.1 + version: 7.29.1 yaml: specifier: 2.8.3 version: 2.8.3 @@ -785,6 +788,10 @@ packages: undici-types@6.21.0: resolution: {integrity: sha512-iwDZqg0QAGrg9Rav5H4n0M64c3mkR59cJ6wQp+7C4nI0gsmExaedaYLNO44eT4AtBBwjbTiGPMlt2Md0T9H9JQ==} + undici@7.29.1: + resolution: {integrity: sha512-RYONW2MeafgYlkVOKYKkA/Ag7BmXqgIWCa8t1m0JcxrQg9pI9lEqRhAOruOBCbAohOa/gkCF+iPi9hrgvTzu6Q==} + engines: {node: '>=20.18.1'} + vite@8.0.16: resolution: {integrity: sha512-h9bXPmJichP5fLmVQo3PyaGSDE2n3aPuomeAlVRm0JLmt4rY6zmPKd59HYI4LNW8oTK7tlTsuC7l/m7awx9Jcw==} engines: {node: ^20.19.0 || >=22.12.0} @@ -1468,6 +1475,8 @@ snapshots: undici-types@6.21.0: {} + undici@7.29.1: {} + vite@8.0.16(@types/node@22.19.1)(esbuild@0.28.1)(tsx@4.22.4)(yaml@2.8.3): dependencies: lightningcss: 1.32.0 diff --git a/src/lib/http.ts b/src/lib/http.ts index 4268f19..fac56b8 100644 --- a/src/lib/http.ts +++ b/src/lib/http.ts @@ -1,4 +1,5 @@ import { readFile } from "node:fs/promises"; +import { Agent, type Dispatcher } from "undici"; import type { CliConfig } from "./config.js"; import { ApiError, NetworkError, UsageError } from "./errors.js"; import { redact } from "./redact.js"; @@ -39,22 +40,17 @@ export async function executeOperationStream( // A streamed response stays open for as long as the server keeps producing events, so the // timeout must bound inactivity, not total duration: it is reset on every received chunk. const idle = startIdleTimeout(url, timeoutMs); + const dispatcher = createRequestDispatcher(timeoutMs); + const send = (request: RequestInit) => + sendRequest(url, { ...request, signal: idle.signal }, timeoutMs, dispatcher); try { - let response = await sendRequest(config, url, { ...init, signal: idle.signal }, timeoutMs); + let response = await send(init); if (response.status === 401 && refresh) { idle.reset(); - response = await retryWithRefreshedToken( - config, - url, - init, - refresh, - response, - timeoutMs, - idle.signal, - ); + response = await retryWithRefreshedToken(init, refresh, response, send); } if (!response.ok) { - const text = await readBody(url, timeoutMs, () => response.text()); + const text = await readBody(url, timeoutMs, () => response.text(), idle.signal); const data = parseResponse(text, response.headers.get("content-type")); const detail = formatErrorDetail(data, response.statusText); throw new ApiError( @@ -65,13 +61,19 @@ export async function executeOperationStream( } const body = response.body; if (!body || !response.headers.get("content-type")?.includes("text/event-stream")) { - const text = await readBody(url, timeoutMs, () => response.text()); + const text = await readBody(url, timeoutMs, () => response.text(), idle.signal); onEvent(parseResponse(text, response.headers.get("content-type"))); return; } - await readBody(url, timeoutMs, () => consumeServerSentEvents(body, onEvent, idle.reset)); + await readBody( + url, + timeoutMs, + () => consumeServerSentEvents(body, onEvent, idle.reset), + idle.signal, + ); } finally { idle.clear(); + await dispatcher.destroy(); } } @@ -236,17 +238,34 @@ async function executeRequest( refresh?: TokenRefresher, timeoutMs = config.timeoutMs, ): Promise> { - let response = await sendRequest(config, url, init, timeoutMs); - if (response.status === 401 && refresh) { - response = await retryWithRefreshedToken(config, url, init, refresh, response, timeoutMs); - } - const text = await readBody(url, timeoutMs, () => response.text()); - const data = parseResponse(text, response.headers.get("content-type")); - if (!response.ok) { - const detail = formatErrorDetail(data, response.statusText); - throw new ApiError(`AskNews API returned ${response.status}: ${detail}`, response.status, data); + const dispatcher = createRequestDispatcher(timeoutMs); + let deadline: ReturnType | undefined; + const send = (request: RequestInit) => { + // Preserve the existing single 401 refresh retry's fresh per-attempt budget. + deadline?.clear(); + deadline = startRequestTimeout(timeoutMs); + return sendRequest(url, { ...request, signal: deadline.signal }, timeoutMs, dispatcher); + }; + try { + let response = await send(init); + if (response.status === 401 && refresh) { + response = await retryWithRefreshedToken(init, refresh, response, send); + } + const text = await readBody(url, timeoutMs, () => response.text(), deadline?.signal); + const data = parseResponse(text, response.headers.get("content-type")); + if (!response.ok) { + const detail = formatErrorDetail(data, response.statusText); + throw new ApiError( + `AskNews API returned ${response.status}: ${detail}`, + response.status, + data, + ); + } + return { data: data as T, headers: response.headers, status: response.status }; + } finally { + deadline?.clear(); + await dispatcher.destroy(); } - return { data: data as T, headers: response.headers, status: response.status }; } function formatErrorDetail(data: unknown, statusText: string): string { @@ -256,28 +275,61 @@ function formatErrorDetail(data: unknown, statusText: string): string { return JSON.stringify(detail); } +// Request-level headers/body timers take precedence over Agent defaults. Set finite +// values at dispatch time, after native fetch has built its (version-dependent) options. +// Scope the dispatcher to one execution; never modify the process-wide dispatcher. +function createRequestDispatcher(timeoutMs: number): Dispatcher { + return new Agent().compose( + (dispatch) => (options, handler) => + dispatch({ ...options, headersTimeout: timeoutMs, bodyTimeout: timeoutMs }, handler), + ); +} + +function startRequestTimeout(timeoutMs: number): { signal: AbortSignal; clear: () => void } { + const controller = new AbortController(); + const timer = setTimeout( + () => controller.abort(new DOMException("Request deadline exceeded", "TimeoutError")), + timeoutMs, + ); + timer.unref(); + return { signal: controller.signal, clear: () => clearTimeout(timer) }; +} + async function sendRequest( - config: CliConfig, url: URL, init: RequestInit, - timeoutMs = config.timeoutMs, + timeoutMs: number, + dispatcher: Dispatcher, ): Promise { try { - return await fetch(url, { signal: AbortSignal.timeout(timeoutMs), ...init }); + // Node 22's fetch types reference Undici 6; the dispatcher protocol is compatible + // with Undici 7 (also used by newer Node). Keep the cast at this native-fetch boundary. + const request = { + ...init, + dispatcher: dispatcher as unknown as NonNullable, + }; + return await fetch(url, request); } catch (error) { - throw new NetworkError(describeNetworkError(url, timeoutMs, error), redact(error)); + const reason = init.signal?.aborted ? init.signal.reason : error; + throw new NetworkError(describeNetworkError(url, timeoutMs, reason), redact(reason)); } } // Runs a response-body read (buffered text or SSE consumption), converting abort/network // failures into the same actionable NetworkError produced for request failures. Without this, // a timeout firing mid-body surfaces as a bare "The operation was aborted" from undici. -async function readBody(url: URL, timeoutMs: number, read: () => Promise): Promise { +async function readBody( + url: URL, + timeoutMs: number, + read: () => Promise, + signal?: AbortSignal, +): Promise { try { return await read(); } catch (error) { if (error instanceof ApiError || error instanceof NetworkError) throw error; - throw new NetworkError(describeNetworkError(url, timeoutMs, error), redact(error)); + const reason = signal?.aborted ? signal.reason : error; + throw new NetworkError(describeNetworkError(url, timeoutMs, reason), redact(reason)); } } @@ -307,21 +359,20 @@ function startIdleTimeout( // On a 401, refresh the token once and retry. If the refresh yields no token (no refresh token, or // the refresh itself fails), keep the original 401 response so the caller surfaces it unchanged. async function retryWithRefreshedToken( - config: CliConfig, - url: URL, init: RequestInit, refresh: TokenRefresher, unauthorized: Response, - timeoutMs = config.timeoutMs, - signal?: AbortSignal, + send: (init: RequestInit) => Promise, ): Promise { const token = await refresh().catch(() => null); if (!token) { return unauthorized; } + // Do not leave an unread 401 body/socket alive while issuing the one auth retry. + await unauthorized.body?.cancel().catch(() => {}); const headers = new Headers(init.headers); headers.set("authorization", `Bearer ${token}`); - return sendRequest(config, url, { ...init, headers, ...(signal ? { signal } : {}) }, timeoutMs); + return send({ ...init, headers }); } function describeNetworkError(url: URL, timeoutMs: number, error: unknown): string { @@ -386,20 +437,26 @@ export async function consumeServerSentEvents( const reader = stream.getReader(); const decoder = new TextDecoder(); let buffer = ""; - while (true) { - const { done, value } = await reader.read(); - onActivity?.(); - buffer += decoder.decode(value, { stream: !done }); - const blocks = buffer.split(/\r?\n\r?\n/); - buffer = blocks.pop() ?? ""; - for (const block of blocks) { - const event = parseEventBlock(block); - if (event !== undefined) onEvent(event); + try { + while (true) { + const { done, value } = await reader.read(); + onActivity?.(); + buffer += decoder.decode(value, { stream: !done }); + const blocks = buffer.split(/\r?\n\r?\n/); + buffer = blocks.pop() ?? ""; + for (const block of blocks) { + const event = parseEventBlock(block); + if (event !== undefined) onEvent(event); + } + if (done) break; } - if (done) break; + const finalEvent = parseEventBlock(buffer); + if (finalEvent !== undefined) onEvent(finalEvent); + } finally { + // Callback failures must also cancel the body, not leave a locked, unread stream. + await reader.cancel().catch(() => {}); + reader.releaseLock(); } - const finalEvent = parseEventBlock(buffer); - if (finalEvent !== undefined) onEvent(finalEvent); } function parseEventBlock(block: string): unknown | undefined { diff --git a/test/http-timeout.test.ts b/test/http-timeout.test.ts new file mode 100644 index 0000000..67499a5 --- /dev/null +++ b/test/http-timeout.test.ts @@ -0,0 +1,147 @@ +import { Agent } from "undici"; +import { afterEach, expect, test, vi } from "vitest"; +import type { CliConfig } from "../src/lib/config.js"; +import { ApiError } from "../src/lib/errors.js"; +import { consumeServerSentEvents, executeRawRequest } from "../src/lib/http.js"; + +const config: CliConfig = { + apiUrl: "http://api.invalid/v1", + authUrl: "http://auth.invalid", + oauthClientId: "test", + output: "json", + configDir: "/tmp/asknews-cli-timeout-test", + timeoutMs: 900_000, + noColor: true, +}; + +afterEach(() => { + vi.useRealTimers(); + vi.unstubAllGlobals(); +}); + +test.each([ + "success", + "api failure", + "network failure", + "body failure", +])("%s clears the buffered timer and destroys the scoped dispatcher", async (outcome) => { + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + const destroy = vi.spyOn(Agent.prototype, "destroy"); + vi.stubGlobal( + "fetch", + vi.fn(async () => { + if (outcome === "network failure") throw new TypeError("fetch failed"); + const response = new Response("{}", { + status: outcome === "api failure" ? 403 : 200, + headers: { "content-type": "application/json" }, + }); + if (outcome === "body failure") { + vi.spyOn(response, "text").mockRejectedValue(new Error("body failed")); + } + return response; + }), + ); + const request = executeRawRequest(config, "test", "GET", "/test"); + if (outcome === "success") await expect(request).resolves.toMatchObject({ data: {} }); + else await expect(request).rejects.toBeInstanceOf(Error); + expect(vi.getTimerCount()).toBe(0); + expect(destroy).toHaveBeenCalled(); + expect(destroy.mock.instances[0]).toHaveProperty("destroyed", true); +}); + +test("401 body is cancelled before the refreshed request, and both attempt timers are cleared", async () => { + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + const cancel = vi.fn(); + const unauthorized = new Response(new ReadableStream({ cancel }), { status: 401 }); + const mockFetch = vi + .fn() + .mockResolvedValueOnce(unauthorized) + .mockImplementationOnce(async () => { + expect(cancel).toHaveBeenCalledOnce(); + expect(vi.getTimerCount()).toBe(1); + return new Response("{}"); + }); + vi.stubGlobal("fetch", mockFetch); + await executeRawRequest(config, "test", "GET", "/test", undefined, async () => "refreshed"); + expect(mockFetch).toHaveBeenCalledTimes(2); + expect(vi.getTimerCount()).toBe(0); +}); + +test.each([ + "complete", + "callback error", + "read error", +])("SSE %s releases the reader and preserves the original error", async (outcome) => { + const cancel = vi.fn(); + const error = new ApiError("consumer error", 403); + const stream = new ReadableStream({ + start(controller) { + if (outcome === "read error") controller.error(error); + else { + controller.enqueue(new TextEncoder().encode('data: {"ok":true}\n\n')); + if (outcome === "complete") controller.close(); + } + }, + cancel, + }); + const consume = consumeServerSentEvents(stream, () => { + if (outcome === "callback error") throw error; + }); + if (outcome === "complete") await expect(consume).resolves.toBeUndefined(); + else await expect(consume).rejects.toBe(error); + expect(stream.locked).toBe(false); + if (outcome === "callback error") expect(cancel).toHaveBeenCalledOnce(); +}); + +test("dispatch-time limits override fetch-supplied headers/body limits", async () => { + const dispatch = vi.spyOn(Agent.prototype, "dispatch").mockReturnValue(true); + vi.stubGlobal("fetch", async (_url: unknown, init: RequestInit) => { + const dispatcher = init.dispatcher as unknown as Agent; + dispatcher.dispatch( + { + origin: "http://api.invalid", + path: "/v1/test", + method: "GET", + headersTimeout: 300_000, + bodyTimeout: 300_000, + }, + {}, + ); + return new Response("{}"); + }); + await executeRawRequest(config, "test", "GET", "/test"); + expect(dispatch).toHaveBeenCalledWith( + expect.objectContaining({ + headersTimeout: 900_000, + bodyTimeout: 900_000, + }), + expect.anything(), + ); +}); + +test("a body reader's generic AbortError uses the original deadline reason", async () => { + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + vi.stubGlobal("fetch", async (_url: unknown, init: RequestInit) => { + const response = new Response("{}"); + vi.spyOn(response, "text").mockImplementation( + () => + new Promise((_resolve, reject) => { + init.signal?.addEventListener( + "abort", + () => { + reject(new DOMException("The operation was aborted", "AbortError")); + }, + { once: true }, + ); + }), + ); + return response; + }); + const result = expect(executeRawRequest(config, "test", "GET", "/test")).rejects.toMatchObject({ + exitCode: 4, + message: expect.stringContaining("timed out after 900000 ms"), + }); + await vi.advanceTimersByTimeAsync(900_000); + await result; + expect(vi.getTimerCount()).toBe(0); +}); diff --git a/test/integration/http-timeout.integration.test.ts b/test/integration/http-timeout.integration.test.ts new file mode 100644 index 0000000..9458695 --- /dev/null +++ b/test/integration/http-timeout.integration.test.ts @@ -0,0 +1,384 @@ +import { channel } from "node:diagnostics_channel"; +import { once } from "node:events"; +import { createServer, type RequestListener, type ServerResponse } from "node:http"; +import type { Socket } from "node:net"; +import { Agent } from "undici"; +import { afterEach, expect, test, vi } from "vitest"; +import type { CliConfig } from "../../src/lib/config.js"; +import { executeOperation, executeOperationStream, executeRawRequest } from "../../src/lib/http.js"; +import type { OperationDefinition } from "../../src/lib/types.js"; + +const cleanups: (() => void | Promise)[] = []; +afterEach(async () => { + for (const cleanup of cleanups.reverse()) await cleanup(); + cleanups.length = 0; + vi.unstubAllGlobals(); +}); + +const research: OperationDefinition = { + operationId: "deep_news", + tag: "chat", + command: "deepnews", + method: "POST", + path: "/v1/chat/deepnews", + summary: "DeepNews", + parameters: [], + requestBody: { required: true, contentTypes: ["application/json"], schema: {} }, + safety: "high-cost", +}; + +async function localServer(handler: RequestListener) { + const sockets = new Set(); + const server = createServer(handler); + server.on("connection", (socket) => { + sockets.add(socket); + socket.on("close", () => sockets.delete(socket)); + }); + server.listen(0, "127.0.0.1"); + await once(server, "listening"); + cleanups.push( + () => + new Promise((resolve) => { + server.close(() => resolve()); + server.closeAllConnections(); + }), + ); + const address = server.address(); + if (!address || typeof address === "string") throw new Error("missing server address"); + const config: CliConfig = { + apiUrl: `http://127.0.0.1:${address.port}/v1`, + authUrl: "http://auth.invalid", + oauthClientId: "test", + output: "json", + configDir: "/tmp/asknews-cli-timeout-test", + timeoutMs: 60_000, + noColor: true, + }; + return { config, sockets }; +} + +function later(response: ServerResponse, ms: number, action: () => void) { + const timer = setTimeout(action, ms); + response.on("close", () => clearTimeout(timer)); +} + +function ticks(response: ServerResponse, ms: number, action: () => void) { + const timer = setInterval(action, ms); + response.on("close", () => clearInterval(timer)); +} + +function observeTimeouts(config: CliConfig) { + const requests: { headersTimeout: number; bodyTimeout: number }[] = []; + const diagnostics = channel("undici:request:create"); + const observe = (message: unknown) => { + const { request } = message as { + request: { + origin: string; + headersTimeout: number; + bodyTimeout: number; + }; + }; + if (String(request.origin) === new URL(config.apiUrl).origin) { + requests.push({ headersTimeout: request.headersTimeout, bodyTimeout: request.bodyTimeout }); + } + }; + diagnostics.subscribe(observe); + cleanups.push(() => diagnostics.unsubscribe(observe)); + return requests; +} + +test("native fetch dispatches the effective finite budget, not the transport defaults", async () => { + const { config } = await localServer((_request, response) => { + response.setHeader("content-type", "application/json"); + later(response, 30, () => response.end('{"ok":true}')); + }); + const dispatched = observeTimeouts(config); + await executeOperation(config, "test", research, {}); + await executeOperation( + { ...config, timeoutMs: 1_200_000, timeoutExplicit: true }, + "test", + research, + {}, + ); + await executeOperation( + { ...config, timeoutMs: 1_000, timeoutExplicit: true }, + "test", + research, + {}, + ); + await executeOperation(config, "test", { ...research, operationId: "other" }, {}); + await executeRawRequest(config, "test", "GET", "/raw"); + expect(dispatched).toEqual( + [900_000, 1_200_000, 1_000, 60_000, 60_000].map((ms) => ({ + headersTimeout: ms, + bodyTimeout: ms, + })), + ); +}); + +test("buffered deadline includes delayed headers and the entire body; chunks do not extend it", async () => { + let calls = 0; + const { config, sockets } = await localServer((_request, response) => { + calls++; + later(response, 150, () => { + response.setHeader("content-type", "application/json"); + response.write("["); + ticks(response, 40, () => response.write("0,")); + }); + }); + const start = performance.now(); + await expect( + executeOperation({ ...config, timeoutMs: 350, timeoutExplicit: true }, "test", research, {}), + ).rejects.toMatchObject({ + exitCode: 4, + message: expect.stringContaining("timed out after 350 ms"), + }); + expect(performance.now() - start).toBeLessThan(1_500); + expect(calls).toBe(1); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test.each([ + "headers", + "body", +])("a silent %s wait expires with the explicit research deadline", async (phase) => { + const { config, sockets } = await localServer((_request, response) => { + if (phase === "body") { + response.setHeader("content-type", "application/json"); + response.write('{"ok":'); + } + }); + await expect( + executeOperation({ ...config, timeoutMs: 150, timeoutExplicit: true }, "test", research, {}), + ).rejects.toMatchObject({ + exitCode: 4, + message: expect.stringContaining("timed out after 150 ms"), + }); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test("a delayed body within the remaining total budget completes and closes its socket", async () => { + const { config, sockets } = await localServer((_request, response) => { + later(response, 50, () => { + response.setHeader("content-type", "application/json"); + response.write('{"ok":'); + later(response, 100, () => response.end("true}")); + }); + }); + await expect( + executeOperation({ ...config, timeoutMs: 500, timeoutExplicit: true }, "test", research, {}), + ).resolves.toMatchObject({ data: { ok: true } }); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test("SSE comment heartbeats extend activity beyond the idle budget without emitting events", async () => { + const { config, sockets } = await localServer((_request, response) => { + response.setHeader("content-type", "text/event-stream"); + response.write(": heartbeat\n\n"); + ticks(response, 40, () => response.write(": heartbeat\n\n")); + later(response, 500, () => response.end('data: {"ok":true}\n\ndata: [DONE]\n\n')); + }); + const dispatched = observeTimeouts(config); + const events: unknown[] = []; + await executeOperationStream( + { ...config, timeoutMs: 200, timeoutExplicit: true }, + "test", + research, + { body: { stream: true } }, + (event) => events.push(event), + ); + expect(events).toEqual([{ ok: true }]); + expect(dispatched).toEqual([{ headersTimeout: 200, bodyTimeout: 200 }]); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test.each([ + "headers", + "after heartbeat", +])("SSE idle abort during %s is actionable and cleans up", async (phase) => { + const { config, sockets } = await localServer((_request, response) => { + if (phase === "after heartbeat") { + response.setHeader("content-type", "text/event-stream"); + response.write(": heartbeat\n\n"); + } + }); + await expect( + executeOperationStream( + { ...config, timeoutMs: 150, timeoutExplicit: true }, + "test", + research, + { body: { stream: true } }, + () => {}, + ), + ).rejects.toMatchObject({ + exitCode: 4, + message: expect.stringContaining("stalled: no data received for 150 ms"), + }); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test("an SSE callback failure cancels the unread body and closes the connection", async () => { + const { config, sockets } = await localServer((_request, response) => { + response.setHeader("content-type", "text/event-stream"); + response.write('data: {"ok":true}\n\n'); + }); + await expect( + executeOperationStream(config, "test", research, { body: { stream: true } }, () => { + throw new Error("consumer failed"); + }), + ).rejects.toMatchObject({ exitCode: 4, message: expect.stringContaining("consumer failed") }); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test.each([ + 403, 500, +])("HTTP %i remains an API error, without an automatic retry", async (status) => { + let calls = 0; + const { config, sockets } = await localServer((_request, response) => { + calls++; + response.writeHead(status, { "content-type": "application/json" }); + response.end('{"detail":"upstream refusal"}'); + }); + const refresh = vi.fn(async () => "unused"); + await expect(executeOperation(config, "test", research, {}, refresh)).rejects.toMatchObject({ + status, + exitCode: status >= 500 ? 6 : 5, + }); + expect(calls).toBe(1); + expect(refresh).not.toHaveBeenCalled(); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test("a broken body remains a network error, not a deadline or an API error; no retry", async () => { + let calls = 0; + const { config, sockets } = await localServer((_request, response) => { + calls++; + response.writeHead(200, { "content-type": "application/json" }); + response.write('{"ok":'); + later(response, 50, () => response.destroy()); + }); + await expect(executeOperation(config, "test", research, {})).rejects.toMatchObject({ + exitCode: 4, + message: expect.stringContaining("failed: UND_ERR_SOCKET"), + }); + expect(calls).toBe(1); + await vi.waitFor(() => expect(sockets.size).toBe(0)); +}); + +test("401 retry cancels an unfinished body, keeps a fresh buffered budget, and retries only once", async () => { + let calls = 0; + let firstResponse: ServerResponse | undefined; + const { config, sockets } = await localServer((_request, response) => { + calls++; + if (calls === 1) { + firstResponse = response; + response.writeHead(401, { "content-type": "application/json" }); + response.write('{"detail":'); + } else { + response.writeHead(401, { "content-type": "application/json" }); + response.end('{"detail":"still unauthorized"}'); + } + }); + const refresh = vi.fn(async () => { + // Refresh already had its own budget before this fix. A new request gets a new deadline. + await new Promise((resolve) => setTimeout(resolve, 250)); + return "refreshed"; + }); + await expect( + executeOperation( + { ...config, timeoutMs: 150, timeoutExplicit: true }, + "test", + research, + {}, + refresh, + ), + ).rejects.toMatchObject({ + status: 401, + exitCode: 5, + message: expect.stringContaining("still unauthorized"), + }); + expect(calls).toBe(2); + expect(refresh).toHaveBeenCalledOnce(); + await vi.waitFor(() => { + expect(firstResponse?.destroyed).toBe(true); + expect(sockets.size).toBe(0); + }); +}); + +// Opt-in LOCAL wall-clock proof, not a live API test. Runs the old/native path with +// default Agent timers alongside the fixed path, for both headers and body inactivity. +// ASKNEWS_LOCAL_TIMEOUT_SMOKE=1 pnpm exec vitest run test/integration/http-timeout.integration.test.ts -t wall-clock +// Allow at least 360 seconds in the outer process runner. +test.runIf(process.env.ASKNEWS_LOCAL_TIMEOUT_SMOKE === "1")( + "wall-clock: headers and body can wait beyond the old 300-second boundary", + async () => { + const delayMs = 305_000; + const { config } = await localServer((request, response) => { + response.setHeader("content-type", "application/json"); + const bodyWait = request.url?.endsWith("/body"); + if (bodyWait) response.write('{"ok":'); + later(response, delayMs, () => response.end(bodyWait ? "true}" : '{"ok":true}')); + }); + const oldAgent = new Agent(); + cleanups.push(async () => { + await oldAgent.destroy(); + }); + const results = await Promise.all( + ["headers", "body"].flatMap((phase) => { + const start = performance.now(); + const old = fetch(`${config.apiUrl}/${phase}`, { + method: research.method, + dispatcher: oldAgent as unknown as NonNullable, + signal: AbortSignal.timeout(900_000), + }) + .then((response) => response.text()) + .then( + () => ({ + phase, + transport: "old", + elapsedMs: performance.now() - start, + code: "unexpected success", + }), + (error) => ({ + phase, + transport: "old", + elapsedMs: performance.now() - start, + code: error.cause?.code, + }), + ); + const fixed = executeOperation( + config, + "test", + { ...research, path: `/v1/${phase}` }, + {}, + ).then((response) => ({ + phase, + transport: "fixed", + elapsedMs: performance.now() - start, + data: response.data, + })); + return [old, fixed]; + }), + ); + console.log( + JSON.stringify({ + node: process.version, + bundledUndici: process.versions.undici, + delayMs, + results, + }), + ); + for (const result of results) { + expect(result.elapsedMs).toBeGreaterThan(300_000); + if ("code" in result) { + expect(result.code).toBe( + result.phase === "headers" ? "UND_ERR_HEADERS_TIMEOUT" : "UND_ERR_BODY_TIMEOUT", + ); + } else { + expect(result.data).toEqual({ ok: true }); + expect(result.elapsedMs).toBeGreaterThanOrEqual(delayMs); + } + } + }, + 345_000, +);