fix(streaming): honor request timeout while waiting for the first token (#826)

The configured request timeout (API_TIMEOUT_MS) only feeds the SDK client
timeout, which on a streaming request is cleared the moment response headers
arrive. Slow local/3P models return 200 headers fast but spend minutes
prefilling before the first SSE token, so that window was governed by the idle
watchdog (CLAUDE_STREAM_IDLE_TIMEOUT_MS, 240s) -- a separate env users cannot
configure. The configured timeout therefore never applied to slow prefill, so
raising it had no effect (#826, follow-up to #449).

Split the stream watchdog into phases: use a first-token budget (tied to the
user's request timeout via CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS) until the first
chunk arrives, then switch to the shorter mid-stream idle budget. The overall
max-duration cap (#766) still backstops trickling bodies; CLI defaults fall back
to prior behavior.
This commit is contained in:
程序员阿江(Relakkes) 2026-06-15 23:34:32 +08:00
parent 3e6fe7d6bb
commit e7a59592de
4 changed files with 91 additions and 12 deletions

View File

@ -316,6 +316,44 @@ describe('ConversationService', () => {
expect(env.HTTPS_PROXY).toBe('http://127.0.0.1:7890')
})
test('buildChildEnv ties the first-token watchdog to the user request timeout so slow prefill is not killed early (#826)', async () => {
const prev = process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS
delete process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS
await fs.writeFile(
path.join(tmpDir, 'settings.json'),
JSON.stringify({ network: { aiRequestTimeoutMs: 600_000 } }),
'utf-8',
)
try {
const service = new ConversationService() as any
const env = (await service.buildChildEnv('/tmp')) as Record<string, string>
// The user's "请求超时" must reach the first-token watchdog, not only the
// SDK client timeout (which on a stream is cleared the moment response
// headers arrive). Otherwise a local/3P model that needs minutes to emit
// its first token gets killed by the 240s idle watchdog no matter how high
// the configured timeout is (#826).
expect(env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS).toBe('600000')
expect(env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS).toBe(env.API_TIMEOUT_MS)
} finally {
if (prev === undefined) delete process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS
else process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS = prev
}
})
test('buildChildEnv lets caller env override the first-token watchdog (#826)', async () => {
const prev = process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS
process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS = '900000'
try {
const service = new ConversationService() as any
const env = (await service.buildChildEnv('/tmp')) as Record<string, string>
expect(env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS).toBe('900000')
} finally {
if (prev === undefined) delete process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS
else process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS = prev
}
})
test('buildChildEnv injects CLAUDE_CODE_OAUTH_TOKEN when official mode + haha oauth token exists', async () => {
const ccHahaDir = path.join(tmpDir, 'cc-haha')
await fs.mkdir(ccHahaDir, { recursive: true })

View File

@ -1121,6 +1121,15 @@ export class ConversationService {
// no completion (#766: "卡住" with slowly growing tokens). This independent
// cap frees such a stream after a fixed duration regardless of trickle.
CLAUDE_STREAM_MAX_DURATION_MS: cleanEnv.CLAUDE_STREAM_MAX_DURATION_MS || '600000',
// Time-to-first-token budget: how long to wait for the FIRST streamed
// chunk after response headers arrive. The idle timer above is the wrong
// knob for slow prefill — it kills healthy local/3P models that take
// minutes to emit their first token (#826). Tie this to the user's
// request-timeout setting (API_TIMEOUT_MS, from networkEnv) so raising
// "请求超时" actually extends how long we wait for the first token. The
// CLI switches to the shorter idle budget once tokens start flowing.
CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS:
cleanEnv.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS || networkEnv.API_TIMEOUT_MS,
// When a stream does get aborted, retry as streaming instead of falling
// back to non-streaming: a non-streaming request must wait for the FULL
// generation before the first response byte, so slow providers can never

View File

@ -10,12 +10,19 @@ export type NetworkSettings = {
}
}
// API_TIMEOUT_MS is the CLI's *time-to-first-byte* budget for streaming
// requests: third-party Anthropic-compatible gateways (sensenova, bailian,
// zhipu, ...) often send no response bytes — not even headers or an SSE ping —
// until prefill finishes, which can take minutes at large contexts. A short
// default here aborts those healthy-but-slow requests dead at exactly this
// timeout (#766), so the default matches the SDK's own 600s.
// aiRequestTimeoutMs is the user-facing "wait for the first reply" budget. It
// drives two CLI knobs in lockstep (see conversationService.buildChildEnv):
// 1. API_TIMEOUT_MS — the SDK client timeout, which on a streaming request
// only covers connection → response headers (the SDK clears it the moment
// headers arrive; the streaming body is not covered).
// 2. CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS — the CLI's first-token watchdog,
// which covers the gap between response headers and the FIRST SSE chunk.
// Together they make the configured timeout span the whole pre-first-token
// window: third-party gateways and local models (sensenova, bailian, zhipu,
// ollama, llama.cpp, ...) often send nothing — not headers, not an SSE ping —
// for minutes while prefilling a large context (#766, #826). Once tokens start
// flowing the CLI hands off to the shorter mid-stream idle watchdog. The
// default matches the SDK's own 600s.
export const DEFAULT_AI_REQUEST_TIMEOUT_MS = 600_000
export const MIN_AI_REQUEST_TIMEOUT_MS = 30_000
export const MAX_AI_REQUEST_TIMEOUT_MS = 1_800_000

View File

@ -1943,7 +1943,21 @@ async function* queryModel(
);
const STREAM_IDLE_TIMEOUT_MS =
parseInt(process.env.CLAUDE_STREAM_IDLE_TIMEOUT_MS || "", 10) || 90_000;
const STREAM_IDLE_WARNING_MS = STREAM_IDLE_TIMEOUT_MS / 2;
// Budget for the FIRST chunk after response headers arrive (the prefill /
// time-to-first-token phase). Slow local models and 3P gateways can spend
// minutes prefilling a large context while emitting zero SSE bytes (#826);
// the SDK request timeout only covers up to the response headers, so the
// mid-stream idle watchdog (STREAM_IDLE_TIMEOUT_MS) otherwise kills these
// healthy-but-slow requests long before the user's configured timeout.
// Falls back to API_TIMEOUT_MS (the user's request-timeout knob), then to
// the idle value so terminal CLI behavior is unchanged when unset.
const STREAM_FIRST_TOKEN_TIMEOUT_MS =
parseInt(process.env.CLAUDE_STREAM_FIRST_TOKEN_TIMEOUT_MS || "", 10) ||
parseInt(process.env.API_TIMEOUT_MS || "", 10) ||
STREAM_IDLE_TIMEOUT_MS;
// The idle watchdog waits the first-token budget until the first chunk
// arrives, then switches to the shorter mid-stream idle budget (#826).
let currentStreamIdleTimeoutMs = STREAM_FIRST_TOKEN_TIMEOUT_MS;
// Overall wall-clock cap for a single streaming response. UNLIKE the idle
// timer, this is NEVER reset by incoming chunks, so it catches upstreams that
// trickle content deltas (e.g. a large tool_use input_json_delta) just fast
@ -1975,6 +1989,10 @@ async function* queryModel(
if (!streamWatchdogEnabled) {
return;
}
// Snapshot the active budget so a fire reports the value it was armed
// with, even if the phase (first-token → idle) flips between arm and fire.
const idleMs = currentStreamIdleTimeoutMs;
const warningMs = idleMs / 2;
streamIdleWarningTimer = setTimeout(
(warnMs) => {
logForDebugging(
@ -1983,15 +2001,15 @@ async function* queryModel(
);
logForDiagnosticsNoPII("warn", "cli_streaming_idle_warning");
},
STREAM_IDLE_WARNING_MS,
STREAM_IDLE_WARNING_MS,
warningMs,
warningMs,
);
streamIdleTimer = setTimeout(() => {
streamIdleAborted = true;
streamAbortReason = "idle";
streamWatchdogFiredAt = performance.now();
logForDebugging(
`Streaming idle timeout: no chunks received for ${STREAM_IDLE_TIMEOUT_MS / 1000}s, aborting stream`,
`Streaming idle timeout: no chunks received for ${idleMs / 1000}s, aborting stream`,
{ level: "error" },
);
logForDiagnosticsNoPII("error", "cli_streaming_idle_timeout");
@ -2000,10 +2018,10 @@ async function* queryModel(
options.model as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
request_id: (streamRequestId ??
"unknown") as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
timeout_ms: STREAM_IDLE_TIMEOUT_MS,
timeout_ms: idleMs,
});
releaseStreamResources();
}, STREAM_IDLE_TIMEOUT_MS);
}, idleMs);
}
resetStreamIdleTimer();
// Arm the overall-duration watchdog exactly once. It is intentionally NOT
@ -2078,6 +2096,13 @@ async function* queryModel(
}
endQueryProfile();
isFirstChunk = false;
// Tokens are flowing — switch the watchdog from the generous
// first-token (prefill) budget to the shorter mid-stream idle budget,
// so a stall *after* output started is still reclaimed quickly (#826).
if (currentStreamIdleTimeoutMs !== STREAM_IDLE_TIMEOUT_MS) {
currentStreamIdleTimeoutMs = STREAM_IDLE_TIMEOUT_MS;
resetStreamIdleTimer();
}
}
switch (part.type) {