From dfa6eb5383149d0e88e5486e7f95056c6fa0e473 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 13 Sep 2026 12:49:03 +0900 Subject: [PATCH] fix(devin): stop the header deadline from killing turns that are still generating A live swe-2 turn at high effort died with `stream disconnected before completion: cloud-direct: time-to-first-byte timeout (60000ms)`. Three such failures were logged, all at ~60s with no output, while a sibling call on the same account was still alive at 76s. The upstream was healthy; we hung up on it. The comment claimed the timer was cancelled "once any byte arrives". It was not: the timer is cleared in the finally that runs when `await fetch` resolves, and fetch resolves on response headers. Cognition withholds the headers until the model emits its first token, so the 60s budget was a generation deadline on the pre-header window. Nothing is on the wire before headers, so "time-to-first-byte" also named a measurement a client cannot take; the constant and the message are renamed to say what they bound. Body silence after headers was never the problem: the per-chunk idle timer covers it at 120s and is untouched. The header budget being the shorter of the two made the pre-header window the tightest part of a long turn, which is backwards. It now defaults to 300s and is overridable through OPENCODEX_DEVIN_TTFB_MS, clamped so a stray value cannot wedge a turn. The failure is also now classifiable. The old abort raised a bare Error, so devinErrorClassification returned {} and src/lib/errors.ts had to guess the status from message text. Bun rejects the fetch with its own AbortError rather than handing back signal.reason, so attaching a typed error to abort() would be discarded; a flag plus an explicit throw in the catch is what actually produces a CloudChatError carrying 504. A caller cancel leaves the flag false and re-throws unchanged. `timeout: 0` makes our deadline the single authority on this hop, matching src/server/responses/fetch-helpers.ts. The tradeoff is recorded in the constant: a peer that goes silent at the TCP level without RST/FIN now hangs for the budget instead of 60s, and this timer is the only bound left, so it must not be removed. A peer that actually dies still rejects immediately. Local product tests, typecheck, build and install: NOT RUN. Hosted exact-head CI on this PR is the merge proof. --- scripts/test-layout/layout.json | 1 + src/adapters/devin/cloud-direct/chat.ts | 74 +++++++++++-- tests/fixtures/test-layout-expected.json | 1 + tests/providers/devin-stream-deadline.test.ts | 100 ++++++++++++++++++ 4 files changed, 168 insertions(+), 8 deletions(-) create mode 100644 tests/providers/devin-stream-deadline.test.ts diff --git a/scripts/test-layout/layout.json b/scripts/test-layout/layout.json index 4f890cba99..e5425730de 100644 --- a/scripts/test-layout/layout.json +++ b/scripts/test-layout/layout.json @@ -641,6 +641,7 @@ "devin-cli-authmode-migration.test.ts": "providers", "devin-cli-login.test.ts": "providers", "devin-hardening.test.ts": "providers", + "devin-stream-deadline.test.ts": "providers", "digitalocean-scaleway-provider.test.ts": "providers", "docs-429-failover-claims.test.ts": "ci-workflows", "docs-bun-source-requirement.test.ts": "ci-workflows", diff --git a/src/adapters/devin/cloud-direct/chat.ts b/src/adapters/devin/cloud-direct/chat.ts index 3e31e97c5c..6e30839aa6 100644 --- a/src/adapters/devin/cloud-direct/chat.ts +++ b/src/adapters/devin/cloud-direct/chat.ts @@ -46,8 +46,33 @@ import { resolveDevinApiBaseUrl } from '../../../oauth/devin/api-base.js'; * we only trigger when the server has genuinely stopped responding. */ const CLOUD_STREAM_IDLE_MS = 120_000; -/** Time-to-first-byte timeout. */ -const CLOUD_STREAM_TTFB_MS = 60_000; +/** + * Budget for the response HEADERS, which is not the same thing as a connect + * timeout. Cognition holds the headers until the model produces its first + * token, so on a high-effort reasoning model this bounds generation. A 60s + * value killed live swe-2 high turns at exactly 60000ms with no output while + * a sibling call on the same account was still alive at 76s, which is the + * defect this constant exists to record. + * + * It has to be at least as generous as the body idle budget above. The cost of + * the larger value is bounded and understood: a peer that goes silent at the + * TCP level without sending RST/FIN now hangs for this long instead of 60s. A + * peer that actually dies still rejects immediately. This timer is the only + * bound on that case once `timeout: 0` is set on the fetch, so it must not be + * removed. Override with OPENCODEX_DEVIN_TTFB_MS. + */ +const CLOUD_STREAM_HEADERS_DEFAULT_MS = 300_000; +/** Upper bound for the override, so a stray value cannot wedge a turn forever. */ +const CLOUD_STREAM_HEADERS_MAX_MS = 1_800_000; +function cloudStreamHeadersMs(): number { + const raw = process.env.OPENCODEX_DEVIN_TTFB_MS?.trim(); + if (!raw) return CLOUD_STREAM_HEADERS_DEFAULT_MS; + const parsed = Number(raw); + if (!Number.isFinite(parsed) || parsed <= 0) return CLOUD_STREAM_HEADERS_DEFAULT_MS; + return Math.min(parsed, CLOUD_STREAM_HEADERS_MAX_MS); +} +/** Test seam for the headers budget; the resolver itself stays private. */ +export const cloudStreamHeadersMsForTests = cloudStreamHeadersMs; /** Maximum acceptable Connect-RPC frame length (16 MB). */ const MAX_FRAME_LEN = 16 * 1024 * 1024; @@ -1115,12 +1140,24 @@ export async function* streamChatEvents(req: CloudChatRequest): AsyncGenerator ttfbController.abort(new Error(`cloud-direct: time-to-first-byte timeout (${CLOUD_STREAM_TTFB_MS}ms)`)), CLOUD_STREAM_TTFB_MS); + const headersMs = cloudStreamHeadersMs(); + // Abort with no reason and remember that we are the one who fired. Bun rejects + // the fetch with its own AbortError rather than handing back `signal.reason`, + // so attaching a typed error to abort() would be discarded; the catch below is + // what actually produces a classifiable failure. + let headersDeadlineFired = false; + const ttfbTimer = setTimeout(() => { + headersDeadlineFired = true; + ttfbController.abort(); + }, headersMs); const ttfbSignal = ttfbController.signal; // Compose req.signal + ttfbSignal. AbortSignal.any was added in Node // 20.3 / Bun 1.0; our `engines` allows Node ≥18, so on Node 18-20.2 the @@ -1148,7 +1185,28 @@ export async function* streamChatEvents(req: CloudChatRequest): AsyncGenerator void): void { + const key = "OPENCODEX_DEVIN_TTFB_MS"; + const before = process.env[key]; + if (value === undefined) delete process.env[key]; + else process.env[key] = value; + try { + run(); + } finally { + if (before === undefined) delete process.env[key]; + else process.env[key] = before; + } +} + +describe("cloud-direct response-headers deadline", () => { + // A 60s budget killed live swe-2 high turns at exactly 60000ms with no output + // while a sibling call on the same account was still alive at 76s. Cognition + // withholds headers until the first token, so this budget bounds generation. + test("the default outlives a reasoning model that thinks past a minute", () => { + withEnv(undefined, () => { + expect(cloudStreamHeadersMsForTests()).toBe(300_000); + }); + }); + + test("the headers budget is not shorter than the body idle budget", () => { + // Inverting these is what made the pre-header window the tightest part of a + // long turn, which is backwards. + const idle = Number(/CLOUD_STREAM_IDLE_MS = ([0-9_]+)/.exec(CHAT_SRC)?.[1]?.replace(/_/g, "")); + expect(idle).toBeGreaterThan(0); + withEnv(undefined, () => { + expect(cloudStreamHeadersMsForTests()).toBeGreaterThanOrEqual(idle); + }); + }); + + test("an operator override is honoured", () => { + withEnv("1000", () => { + expect(cloudStreamHeadersMsForTests()).toBe(1000); + }); + }); + + test("an override is clamped so a stray value cannot wedge a turn forever", () => { + withEnv("999999999", () => { + expect(cloudStreamHeadersMsForTests()).toBe(1_800_000); + }); + }); + + test.each(["", " ", "0", "-5", "not-a-number"])("a useless override %p falls back to the default", (raw) => { + withEnv(raw, () => { + expect(cloudStreamHeadersMsForTests()).toBe(300_000); + }); + }); +}); + +describe("cloud-direct headers-deadline failure is ours, not the upstream", () => { + // The old abort raised a bare Error, so devinErrorClassification returned {} + // and the failure was inferred from message text as an upstream 502/504. + test("the deadline error classifies as a gateway timeout the caller may retry", () => { + const err = new CloudChatError("cloud-direct: no response headers within 300000ms", undefined, undefined, 504); + expect(devinErrorClassification(err)).toEqual({ status: 504, retryable: true }); + }); + + test("a bare Error still classifies as nothing, which is why the status is set explicitly", () => { + expect(devinErrorClassification(new Error("cloud-direct: no response headers within 300000ms"))).toEqual({}); + }); + + test("the message no longer claims a first-byte measurement it cannot make", () => { + // Nothing is on the wire before headers, so "time-to-first-byte" described a + // measurement that does not exist. Dropping the word "timeout" from it is why + // the explicit 504 above is mandatory rather than cosmetic. + expect(CHAT_SRC).not.toContain("time-to-first-byte"); + }); +}); + +describe("cloud-direct headers deadline guards", () => { + test("the abort callback records that we fired before aborting", () => { + // Bun rejects the fetch with its own AbortError instead of handing back + // signal.reason, so a typed error passed to abort() would be discarded and + // the catch could not tell our deadline from a caller cancel. + expect(CHAT_SRC).toMatch(/headersDeadlineFired = true;\s*\n\s*ttfbController\.abort\(\);/); + expect(CHAT_SRC).not.toMatch(/ttfbController\.abort\(new /); + }); + + test("the GetChatMessage fetch disables the competing runtime timeout", () => { + // Two independent deadlines on one hop means the shorter wins silently and + // this function can no longer explain its own failure. + const call = CHAT_SRC.slice(CHAT_SRC.indexOf("ApiServerService/GetChatMessage")); + expect(call.slice(0, call.indexOf("} as RequestInit"))).toContain("timeout: 0"); + }); + + test("a caller cancel is re-thrown unchanged", () => { + expect(CHAT_SRC).toMatch(/if \(headersDeadlineFired\) \{[\s\S]*?\}\s*\n\s*throw err;/); + }); +});