|
| 1 | +/** |
| 2 | + * @vitest-environment node |
| 3 | + * |
| 4 | + * A stalled model call surfaces only the runtime's own `TimeoutError: The |
| 5 | + * operation timed out.`, which cannot distinguish "never answered" from |
| 6 | + * "answered but the body never completed" — opposite causes with opposite fixes. |
| 7 | + * These cover the phase annotation that makes the distinction observable from the |
| 8 | + * execution trace, which survives when a task stops shipping logs. |
| 9 | + */ |
| 10 | +import { beforeEach, describe, expect, it, vi } from 'vitest' |
| 11 | +import { executeResponsesProviderRequest } from '@/providers/openai/core' |
| 12 | +import type { ProviderRequest } from '@/providers/types' |
| 13 | + |
| 14 | +vi.mock('@/providers', () => ({ MAX_TOOL_ITERATIONS: 5 })) |
| 15 | + |
| 16 | +vi.mock('@/providers/utils', () => ({ |
| 17 | + isFunctionToolCall: () => false, |
| 18 | + calculateCost: () => ({ input: 0, output: 0, total: 0 }), |
| 19 | + sumToolCosts: () => 0, |
| 20 | + enforceStrictSchema: (schema: unknown) => schema, |
| 21 | + prepareToolExecution: () => ({ toolParams: {}, executionParams: {} }), |
| 22 | + prepareToolsWithUsageControl: (tools: unknown[]) => ({ |
| 23 | + tools, |
| 24 | + toolChoice: undefined, |
| 25 | + forcedTools: [], |
| 26 | + hasFilteredTools: false, |
| 27 | + }), |
| 28 | + trackForcedToolUsage: () => ({ hasUsedForcedTool: false, usedForcedTools: [] }), |
| 29 | + supportsReasoningEffort: () => false, |
| 30 | +})) |
| 31 | + |
| 32 | +vi.mock('@/tools', () => ({ executeTool: vi.fn() })) |
| 33 | + |
| 34 | +/** |
| 35 | + * Exactly what the runtime raises when a fetch deadline fires: a `DOMException`, |
| 36 | + * NOT a plain `Error`. The distinction is load-bearing — `DOMException.message` is a |
| 37 | + * readonly getter, so annotating by assignment throws a TypeError and replaces the |
| 38 | + * real failure. Constructing a plain Error here would let that regression pass. |
| 39 | + */ |
| 40 | +function timeoutError() { |
| 41 | + return new DOMException('The operation timed out.', 'TimeoutError') |
| 42 | +} |
| 43 | + |
| 44 | +/** |
| 45 | + * A response whose body never settles until the request's signal aborts — the shape of |
| 46 | + * the `/v1/responses` stall. Rejects immediately if the signal already aborted, so the |
| 47 | + * body can never outlive an abort that landed before the listener attached. |
| 48 | + */ |
| 49 | +function stallingBody(init: RequestInit, responseInit: Partial<Response> = {}) { |
| 50 | + return { |
| 51 | + ok: true, |
| 52 | + status: 200, |
| 53 | + headers: new Headers(), |
| 54 | + ...responseInit, |
| 55 | + json: () => |
| 56 | + new Promise((_resolve, reject) => { |
| 57 | + if (init.signal?.aborted) { |
| 58 | + reject(timeoutError()) |
| 59 | + return |
| 60 | + } |
| 61 | + init.signal?.addEventListener('abort', () => reject(timeoutError()), { once: true }) |
| 62 | + }), |
| 63 | + } |
| 64 | +} |
| 65 | + |
| 66 | +describe('OpenAI transport phase annotation', () => { |
| 67 | + const logger = { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() } as any |
| 68 | + |
| 69 | + beforeEach(() => vi.clearAllMocks()) |
| 70 | + |
| 71 | + function run(fetchMock: unknown, request: Partial<ProviderRequest> = {}) { |
| 72 | + return executeResponsesProviderRequest( |
| 73 | + { apiKey: 'k', model: 'gpt-5.5', messages: [{ role: 'user', content: 'hi' }], ...request }, |
| 74 | + { |
| 75 | + providerId: 'openai', |
| 76 | + providerLabel: 'OpenAI', |
| 77 | + modelName: 'gpt-5.5', |
| 78 | + endpoint: 'https://api.openai.com/v1/responses', |
| 79 | + headers: { Authorization: 'Bearer k' }, |
| 80 | + logger, |
| 81 | + fetch: fetchMock as typeof fetch, |
| 82 | + } |
| 83 | + ) |
| 84 | + } |
| 85 | + |
| 86 | + it('names the body phase, with response metadata, when headers arrived but the body stalled', async () => { |
| 87 | + const stalledBody = { |
| 88 | + ok: true, |
| 89 | + status: 200, |
| 90 | + headers: new Headers({ 'content-length': '32116', 'content-encoding': 'br' }), |
| 91 | + json: () => Promise.reject(timeoutError()), |
| 92 | + } |
| 93 | + |
| 94 | + await expect(run(vi.fn().mockResolvedValue(stalledBody))).rejects.toThrow( |
| 95 | + /phase=reading-response-body/ |
| 96 | + ) |
| 97 | + }) |
| 98 | + |
| 99 | + it('carries the status, content-length and content-encoding of the stalled response', async () => { |
| 100 | + const stalledBody = { |
| 101 | + ok: true, |
| 102 | + status: 200, |
| 103 | + headers: new Headers({ 'content-length': '32116', 'content-encoding': 'br' }), |
| 104 | + json: () => Promise.reject(timeoutError()), |
| 105 | + } |
| 106 | + |
| 107 | + const error = await run(vi.fn().mockResolvedValue(stalledBody)).catch((e) => e) |
| 108 | + expect(error.message).toContain('status=200') |
| 109 | + expect(error.message).toContain('contentLength=32116') |
| 110 | + expect(error.message).toContain('contentEncoding=br') |
| 111 | + expect(error.message).toMatch(/ttfbMs=\d+/) |
| 112 | + }) |
| 113 | + |
| 114 | + /** |
| 115 | + * `x-request-id` is the only identifier OpenAI support can trace a call by, and a |
| 116 | + * stalled request is precisely when we need to hand them one. |
| 117 | + */ |
| 118 | + it('carries the OpenAI x-request-id of the stalled response', async () => { |
| 119 | + const stalledBody = { |
| 120 | + ok: true, |
| 121 | + status: 200, |
| 122 | + headers: new Headers({ 'x-request-id': 'req_abc123', 'content-length': '32116' }), |
| 123 | + json: () => Promise.reject(timeoutError()), |
| 124 | + } |
| 125 | + |
| 126 | + const error = await run(vi.fn().mockResolvedValue(stalledBody)).catch((e) => e) |
| 127 | + expect(error.message).toContain('requestId=req_abc123') |
| 128 | + }) |
| 129 | + |
| 130 | + it('bounds a non-JSON error body instead of pasting a gateway page into the error', async () => { |
| 131 | + const htmlError = { |
| 132 | + ok: false, |
| 133 | + status: 502, |
| 134 | + headers: new Headers(), |
| 135 | + text: () => Promise.resolve(`<html><body>${'x'.repeat(5000)}</body></html>`), |
| 136 | + } |
| 137 | + |
| 138 | + const error = await run(vi.fn().mockResolvedValue(htmlError)).catch((e) => e) |
| 139 | + expect(error.message.length).toBeLessThan(700) |
| 140 | + }) |
| 141 | + |
| 142 | + it('names the header phase when nothing came back at all', async () => { |
| 143 | + const error = await run(vi.fn().mockRejectedValue(timeoutError())).catch((e) => e) |
| 144 | + expect(error.message).toContain('phase=awaiting-response-headers') |
| 145 | + // No response existed, so no response metadata may be claimed. |
| 146 | + expect(error.message).not.toContain('status=') |
| 147 | + }) |
| 148 | + |
| 149 | + it('does not retry a stalled body — the endpoint ignores Idempotency-Key, so a retry would double-create', async () => { |
| 150 | + const fetchMock = vi |
| 151 | + .fn() |
| 152 | + .mockImplementation((_url: string, init: RequestInit) => Promise.resolve(stallingBody(init))) |
| 153 | + |
| 154 | + vi.useFakeTimers() |
| 155 | + try { |
| 156 | + const promise = run(fetchMock).catch((e) => e) |
| 157 | + await vi.advanceTimersByTimeAsync(120_000) |
| 158 | + await promise |
| 159 | + } finally { |
| 160 | + vi.useRealTimers() |
| 161 | + } |
| 162 | + |
| 163 | + expect(fetchMock).toHaveBeenCalledTimes(1) |
| 164 | + const sent = fetchMock.mock.calls[0][1].headers as Record<string, string> |
| 165 | + expect(sent['Idempotency-Key']).toBeUndefined() |
| 166 | + }) |
| 167 | + |
| 168 | + it('bounds a stalled body instead of waiting for the runtime socket wall', async () => { |
| 169 | + const fetchMock = vi |
| 170 | + .fn() |
| 171 | + .mockImplementation((_url: string, init: RequestInit) => Promise.resolve(stallingBody(init))) |
| 172 | + |
| 173 | + vi.useFakeTimers() |
| 174 | + let error: any |
| 175 | + try { |
| 176 | + const promise = run(fetchMock).catch((e) => e) |
| 177 | + await vi.advanceTimersByTimeAsync(120_000) |
| 178 | + error = await promise |
| 179 | + } finally { |
| 180 | + vi.useRealTimers() |
| 181 | + } |
| 182 | + |
| 183 | + expect(error.message).toContain('phase=reading-response-body') |
| 184 | + }) |
| 185 | + |
| 186 | + it('leaves a self-describing API error untouched', async () => { |
| 187 | + const apiError = { |
| 188 | + ok: false, |
| 189 | + status: 429, |
| 190 | + headers: new Headers(), |
| 191 | + text: () => Promise.resolve(JSON.stringify({ error: { message: 'Rate limit reached' } })), |
| 192 | + } |
| 193 | + |
| 194 | + const error = await run(vi.fn().mockResolvedValue(apiError)).catch((e) => e) |
| 195 | + expect(error.message).toContain('Rate limit reached') |
| 196 | + expect(error.message).not.toContain('phase=') |
| 197 | + }) |
| 198 | + |
| 199 | + /** |
| 200 | + * The load-bearing design decision. `/v1/responses` withholds its 200 until generation |
| 201 | + * has finished, so all think time is time-to-headers — measured at 14545ms to headers |
| 202 | + * and 1ms of body on a real long call. Bounding headers would therefore fail healthy |
| 203 | + * reasoning runs. If someone later "tidies" the deadline to cover the whole request, |
| 204 | + * this test is what stops it. |
| 205 | + */ |
| 206 | + it('does not bound time-to-headers, however long generation takes', async () => { |
| 207 | + const completed = { |
| 208 | + id: 'resp_1', |
| 209 | + status: 'completed', |
| 210 | + output: [ |
| 211 | + { type: 'message', role: 'assistant', content: [{ type: 'output_text', text: 'ok' }] }, |
| 212 | + ], |
| 213 | + usage: { input_tokens: 1, output_tokens: 1, total_tokens: 2 }, |
| 214 | + } |
| 215 | + /** |
| 216 | + * Headers arrive only after far longer than the body budget. The mock honours the |
| 217 | + * signal the way a real fetch does, so a deadline armed before headers would reject |
| 218 | + * here — that is what makes this test able to fail. |
| 219 | + */ |
| 220 | + const fetchMock = vi.fn().mockImplementation( |
| 221 | + (_url: string, init: RequestInit) => |
| 222 | + new Promise((resolve, reject) => { |
| 223 | + if (init.signal?.aborted) { |
| 224 | + reject(timeoutError()) |
| 225 | + return |
| 226 | + } |
| 227 | + init.signal?.addEventListener('abort', () => reject(timeoutError()), { once: true }) |
| 228 | + setTimeout( |
| 229 | + () => |
| 230 | + resolve({ |
| 231 | + ok: true, |
| 232 | + status: 200, |
| 233 | + headers: new Headers(), |
| 234 | + json: () => Promise.resolve(completed), |
| 235 | + }), |
| 236 | + 10 * 60_000 |
| 237 | + ) |
| 238 | + }) |
| 239 | + ) |
| 240 | + |
| 241 | + vi.useFakeTimers() |
| 242 | + try { |
| 243 | + const promise = run(fetchMock) |
| 244 | + await vi.advanceTimersByTimeAsync(11 * 60_000) |
| 245 | + await expect(promise).resolves.toBeDefined() |
| 246 | + } finally { |
| 247 | + vi.useRealTimers() |
| 248 | + } |
| 249 | + }) |
| 250 | + |
| 251 | + it('does not arm the body deadline on a healthy fast response', async () => { |
| 252 | + const completed = { |
| 253 | + id: 'resp_1', |
| 254 | + status: 'completed', |
| 255 | + output: [ |
| 256 | + { type: 'message', role: 'assistant', content: [{ type: 'output_text', text: 'ok' }] }, |
| 257 | + ], |
| 258 | + usage: { input_tokens: 1, output_tokens: 1, total_tokens: 2 }, |
| 259 | + } |
| 260 | + const fetchMock = vi.fn().mockResolvedValue({ |
| 261 | + ok: true, |
| 262 | + status: 200, |
| 263 | + headers: new Headers(), |
| 264 | + json: () => Promise.resolve(completed), |
| 265 | + }) |
| 266 | + |
| 267 | + await expect(run(fetchMock)).resolves.toBeDefined() |
| 268 | + expect(fetchMock).toHaveBeenCalledTimes(1) |
| 269 | + }) |
| 270 | + |
| 271 | + /** |
| 272 | + * The workflow timeout aborts `request.abortSignal` with `DOMException('timeout', |
| 273 | + * 'AbortError')`. It must surface as the caller's abort, never be relabelled as a |
| 274 | + * provider body stall — the two have different owners and different fixes. |
| 275 | + */ |
| 276 | + it('surfaces a workflow timeout as an abort, not as a body stall', async () => { |
| 277 | + const workflow = new AbortController() |
| 278 | + const fetchMock = vi.fn().mockImplementation((_url: string, init: RequestInit) => { |
| 279 | + queueMicrotask(() => workflow.abort(new DOMException('timeout', 'AbortError'))) |
| 280 | + return Promise.resolve(stallingBody(init)) |
| 281 | + }) |
| 282 | + |
| 283 | + const error = await run(fetchMock, { abortSignal: workflow.signal }).catch((e) => e) |
| 284 | + |
| 285 | + expect(fetchMock).toHaveBeenCalledTimes(1) |
| 286 | + expect(error.message).not.toContain('response body stalled') |
| 287 | + }) |
| 288 | +}) |
0 commit comments