Skip to content

Commit f07e6ef

Browse files
authored
fix(agent-core): bound hung model requests with first-event and idle timeouts (#428)
* fix: bound hung model requests so the retry path runs (#425) A provider that accepts a request but never sends a response held the turn for the transport default (undici headers timeout, ~300 s) before the existing retry path ran. During that window the TUI showed Loading, queued follow-ups, and /retry and /goal clear appeared to do nothing. - agent-core: wrap every physical model request (each withLLMRetry attempt, agent and compaction scopes) in a stream watchdog. No first event within 120 s, or no event for 300 s after the first, aborts the attempt and ends the stream with a retryable "LLM request timed out" error (stopReason "error", not "aborted"), so BYOK and managed providers retry it. Caller aborts pass through unchanged. Bounds are configurable via LLMModelConfig.firstEventTimeoutMs / streamIdleTimeoutMs or MCODE_LLM_FIRST_EVENT_TIMEOUT_MS / MCODE_LLM_STREAM_IDLE_TIMEOUT_MS (0 disables). - tui: /retry during a live run now says "Stop the running turn before using /retry." instead of "There is no failed response to retry"; /goal clear and /goal pause during a live run say the current response keeps running and that Esc interrupts it. - Tests: never-responding fake provider and real HTTP server that accepts but never answers; the attempt fails within the bound, retries and recovers, a fully hung turn fails and the next turn on the same runner completes. Document the bounds in docs/tui-capabilities.md. * fix: keep prior first-response wait and stop reading abandoned streams (#425) Review follow-up for the model request timeouts: - Default the first-event bound to 300 s, matching undici's headers timeout that was the effective previous wait, so no request that used to succeed now times out. The idle bound stays at 300 s. - Timeout errors name the setting that fired (MCODE_LLM_FIRST_EVENT_TIMEOUT_MS or MCODE_LLM_STREAM_IDLE_TIMEOUT_MS, or the host's per-model firstEventTimeoutMs/streamIdleTimeoutMs). - When a bound fires, the wrapper stops waiting on the inner stream even if the provider ignores the abort: the pending read races a stop signal, and the inner iterator is released without being awaited. Refs #425 --------- Co-authored-by: Tao He <hetaoBackend@users.noreply.github.com>
1 parent 7ea1c8c commit f07e6ef

15 files changed

Lines changed: 879 additions & 4 deletions

File tree

‎docs/tui-capabilities.md‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,20 @@ The evidence column summarizes the historical TUI 0.3.11 restoration record from
8080
| Files, shell, subagents, sessions, headless, ACP | Actual runtime retained | BYOK, file reads, session resume, ACP, sandbox, and status protocol tests |
8181
| Built-in skills, MCP, plugin tools | Original TUI assets and activation conditions retained | Asset build, plugin, and MCP tests; no claim that every skill has passed a real task |
8282

83+
## Model request timeouts
84+
85+
Each model request attempt has a first-response bound: if the provider accepts
86+
the request but sends no response within 300 seconds, the attempt is aborted
87+
and reported as a retryable timeout, so the normal model-request retry runs
88+
instead of waiting for the 20-minute overall request limit. 300 seconds matches
89+
the transport's previous effective wait for response headers. After the first
90+
response event, a stream that stays silent for 300 seconds is failed the same
91+
way; once visible output has started, the turn fails rather than retrying.
92+
Override the bounds in milliseconds with `MCODE_LLM_FIRST_EVENT_TIMEOUT_MS` and
93+
`MCODE_LLM_STREAM_IDLE_TIMEOUT_MS`; `0` disables a bound. Embedding hosts can
94+
also set `firstEventTimeoutMs` and `streamIdleTimeoutMs` per model. The timeout error names
95+
the setting that fired. The 20-minute overall request limit still applies.
96+
8397
## Local Bash execution
8498

8599
When the current turn includes native `task_output`, foreground Bash waits up to

‎packages/agent-core/src/pi-turn-runner/defaults.ts‎

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,34 @@ export const defaultNowMs = () => Date.now();
2020
*/
2121
export const LLM_REQUEST_TIMEOUT_MS = 20 * 60 * 1000;
2222

23+
/**
24+
* Default per-attempt wait for the first provider stream event. Built-in
25+
* providers emit their first event once response headers arrive, so this is
26+
* a first-byte bound: a request the provider accepted but never answers is
27+
* failed as a retryable timeout instead of waiting for
28+
* {@link LLM_REQUEST_TIMEOUT_MS}. The default matches undici's 300 s headers
29+
* timeout, the effective previous wait, so no request that used to succeed
30+
* now times out; the bound also applies to custom fetch implementations.
31+
* Override with {@link LLM_FIRST_EVENT_TIMEOUT_ENV} or
32+
* `LLMModelConfig.firstEventTimeoutMs`; `0` disables it.
33+
*/
34+
export const LLM_FIRST_EVENT_TIMEOUT_MS = 300 * 1000;
35+
36+
/**
37+
* Default per-attempt maximum gap between provider stream events after the
38+
* first one. Kept at the undici body-timeout default so models that reason
39+
* silently for minutes are not cut off; the bound now also applies to custom
40+
* fetch implementations. Override with {@link LLM_STREAM_IDLE_TIMEOUT_ENV} or
41+
* `LLMModelConfig.streamIdleTimeoutMs`; `0` disables it.
42+
*/
43+
export const LLM_STREAM_IDLE_TIMEOUT_MS = 300 * 1000;
44+
45+
/** Environment override (milliseconds) for {@link LLM_FIRST_EVENT_TIMEOUT_MS}. */
46+
export const LLM_FIRST_EVENT_TIMEOUT_ENV = 'MCODE_LLM_FIRST_EVENT_TIMEOUT_MS';
47+
48+
/** Environment override (milliseconds) for {@link LLM_STREAM_IDLE_TIMEOUT_MS}. */
49+
export const LLM_STREAM_IDLE_TIMEOUT_ENV = 'MCODE_LLM_STREAM_IDLE_TIMEOUT_MS';
50+
2351
export const defaultMessageIdAllocator: PiMessageIdAllocator = {
2452
async allocateAssistantMessageId() {
2553
// crypto.randomUUID is available in Node >=18 and modern runtimes.

‎packages/agent-core/src/pi-turn-runner/index.ts‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,19 @@ export {
2525
type PiTurnRunnerOptions,
2626
} from './pi-turn-runner.js';
2727
export { composeStreamFn } from './llm.js';
28+
export {
29+
LLM_FIRST_EVENT_TIMEOUT_ENV,
30+
LLM_FIRST_EVENT_TIMEOUT_MS,
31+
LLM_STREAM_IDLE_TIMEOUT_ENV,
32+
LLM_STREAM_IDLE_TIMEOUT_MS,
33+
} from './defaults.js';
34+
export {
35+
LLM_STREAM_TIMEOUT_MESSAGE_PREFIX,
36+
resolveLLMStreamTimeouts,
37+
withLLMStreamTimeouts,
38+
type LLMStreamTimeoutConfig,
39+
type LLMStreamTimeouts,
40+
} from './llm-stream-timeout.js';
2841
export { normalizeAbortSource } from './types.js';
2942
export {
3043
DEFAULT_LLM_RETRY_POLICY,
Lines changed: 261 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,261 @@
1+
import type { StreamFn } from '@earendil-works/pi-agent-core';
2+
import {
3+
createAssistantMessageEventStream,
4+
streamSimple,
5+
type AssistantMessage,
6+
type AssistantMessageEvent,
7+
type AssistantMessageEventStream,
8+
type Model,
9+
type Api,
10+
} from '@earendil-works/pi-ai';
11+
import {
12+
LLM_FIRST_EVENT_TIMEOUT_MS,
13+
LLM_FIRST_EVENT_TIMEOUT_ENV,
14+
LLM_STREAM_IDLE_TIMEOUT_ENV,
15+
LLM_STREAM_IDLE_TIMEOUT_MS,
16+
} from './defaults.js';
17+
18+
/**
19+
* Per-attempt watchdog for provider streams.
20+
*
21+
* `firstEventTimeoutMs` bounds the wait for the first stream event. The
22+
* built-in providers emit `start` only after the HTTP response headers
23+
* arrive, so this is effectively a first-byte timeout: a request the provider
24+
* accepted but never answers fails here and is retried instead of waiting for
25+
* the 20 min outer request bound (or a custom fetch's own transport default).
26+
*
27+
* `idleTimeoutMs` bounds the gap between consecutive events after the first
28+
* one, so a stream that stalls mid-response is also failed.
29+
*
30+
* `0` disables the corresponding timer.
31+
*/
32+
export interface LLMStreamTimeouts {
33+
readonly firstEventTimeoutMs: number;
34+
readonly idleTimeoutMs: number;
35+
}
36+
37+
export interface LLMStreamTimeoutConfig {
38+
readonly firstEventTimeoutMs?: number;
39+
readonly streamIdleTimeoutMs?: number;
40+
}
41+
42+
/** Marker included in every synthesized timeout message; matches the shared timeout classifier. */
43+
export const LLM_STREAM_TIMEOUT_MESSAGE_PREFIX = 'LLM request timed out';
44+
45+
/**
46+
* Resolve effective timeouts. Precedence: explicit host config, then the
47+
* environment override, then the built-in default. Invalid values (negative,
48+
* non-integer, non-numeric) fall through to the next source.
49+
*/
50+
export function resolveLLMStreamTimeouts(
51+
config: LLMStreamTimeoutConfig = {},
52+
env: Readonly<Record<string, string | undefined>> = readProcessEnv(),
53+
): LLMStreamTimeouts {
54+
return {
55+
firstEventTimeoutMs:
56+
validTimeout(config.firstEventTimeoutMs) ??
57+
parseTimeout(env[LLM_FIRST_EVENT_TIMEOUT_ENV]) ??
58+
LLM_FIRST_EVENT_TIMEOUT_MS,
59+
idleTimeoutMs:
60+
validTimeout(config.streamIdleTimeoutMs) ??
61+
parseTimeout(env[LLM_STREAM_IDLE_TIMEOUT_ENV]) ??
62+
LLM_STREAM_IDLE_TIMEOUT_MS,
63+
};
64+
}
65+
66+
/**
67+
* Wrap a StreamFn so each invocation (each physical request, including every
68+
* retry attempt made by `withLLMRetry`) is guarded by the watchdog.
69+
*
70+
* On timeout the inner request is aborted through a linked signal and the
71+
* returned stream ends with a terminal `error` event whose stop reason is
72+
* `error` (not `aborted`), so the retry layer treats it as a retryable
73+
* transport timeout rather than a user cancellation. A caller abort is passed
74+
* through unchanged and never reported as a timeout.
75+
*/
76+
export function withLLMStreamTimeouts(
77+
inner: StreamFn | undefined,
78+
timeouts: LLMStreamTimeouts,
79+
): StreamFn {
80+
const base = inner ?? streamSimple;
81+
if (timeouts.firstEventTimeoutMs <= 0 && timeouts.idleTimeoutMs <= 0) return base;
82+
return ((model, context, options) => {
83+
const callerSignal = options?.signal;
84+
const controller = new AbortController();
85+
const out = createAssistantMessageEventStream();
86+
let finished = false;
87+
let timer: ReturnType<typeof setTimeout> | undefined;
88+
let lastPartial: AssistantMessage | undefined;
89+
// Resolves when the wrapper is finished for any reason, so the read loop
90+
// below stops even if the inner stream ignores the abort and never yields
91+
// or settles again.
92+
let signalStopped!: () => void;
93+
const stopped = new Promise<typeof STOPPED>((resolve) => {
94+
signalStopped = () => resolve(STOPPED);
95+
});
96+
97+
const clearTimer = () => {
98+
if (timer !== undefined) clearTimeout(timer);
99+
timer = undefined;
100+
};
101+
const onCallerAbort = () => {
102+
clearTimer();
103+
controller.abort(callerSignal?.reason);
104+
};
105+
const finish = () => {
106+
finished = true;
107+
clearTimer();
108+
callerSignal?.removeEventListener('abort', onCallerAbort);
109+
signalStopped();
110+
};
111+
const arm = (ms: number, phase: 'first' | 'idle') => {
112+
clearTimer();
113+
if (ms <= 0 || finished) return;
114+
timer = setTimeout(() => {
115+
if (finished || callerSignal?.aborted) return;
116+
finish();
117+
const message = timeoutMessage(phase, ms);
118+
controller.abort(new LLMStreamTimeoutError(message));
119+
const error: AssistantMessage = {
120+
...snapshot(lastPartial, model),
121+
stopReason: 'error',
122+
errorMessage: message,
123+
};
124+
out.push({ type: 'error', reason: 'error', error });
125+
out.end();
126+
}, ms);
127+
// Never keep the process alive only for the watchdog.
128+
(timer as { unref?: () => void }).unref?.();
129+
};
130+
131+
if (callerSignal?.aborted) {
132+
controller.abort(callerSignal.reason);
133+
} else {
134+
callerSignal?.addEventListener('abort', onCallerAbort, { once: true });
135+
arm(timeouts.firstEventTimeoutMs, 'first');
136+
}
137+
138+
void (async () => {
139+
try {
140+
const opened = await Promise.race([
141+
Promise.resolve(base(model, context, { ...(options ?? {}), signal: controller.signal })),
142+
stopped,
143+
]);
144+
if (opened === STOPPED) return;
145+
const stream: AssistantMessageEventStream = opened;
146+
const iterator = stream[Symbol.asyncIterator]();
147+
for (;;) {
148+
const next = await Promise.race([iterator.next(), stopped]);
149+
if (next === STOPPED || finished) {
150+
releaseIterator(iterator);
151+
return;
152+
}
153+
if (next.done) break;
154+
const event = next.value;
155+
const partial = partialOf(event);
156+
if (partial) lastPartial = partial;
157+
if (event.type === 'done' || event.type === 'error') {
158+
finish();
159+
out.push(event);
160+
out.end();
161+
return;
162+
}
163+
arm(timeouts.idleTimeoutMs, 'idle');
164+
out.push(event);
165+
}
166+
if (!finished) {
167+
// Inner stream ended without a terminal event; mirror its result.
168+
finish();
169+
const final = await stream.result();
170+
out.push(
171+
final.stopReason === 'error' || final.stopReason === 'aborted'
172+
? { type: 'error', reason: final.stopReason, error: final }
173+
: { type: 'done', reason: final.stopReason, message: final },
174+
);
175+
out.end();
176+
}
177+
} catch (error) {
178+
if (finished) return;
179+
finish();
180+
const aborted = callerSignal?.aborted === true;
181+
out.push({
182+
type: 'error',
183+
reason: aborted ? 'aborted' : 'error',
184+
error: {
185+
...snapshot(lastPartial, model),
186+
stopReason: aborted ? 'aborted' : 'error',
187+
errorMessage: error instanceof Error ? error.message : String(error),
188+
},
189+
});
190+
out.end();
191+
}
192+
})();
193+
194+
return out;
195+
}) as StreamFn;
196+
}
197+
198+
const STOPPED: unique symbol = Symbol('llm-stream-timeout-stopped');
199+
200+
/** Ask the inner stream to stop without waiting on one that may never settle. */
201+
function releaseIterator(iterator: AsyncIterator<AssistantMessageEvent>): void {
202+
void Promise.resolve()
203+
.then(() => iterator.return?.())
204+
.catch(() => undefined);
205+
}
206+
207+
export class LLMStreamTimeoutError extends Error {
208+
override readonly name = 'TimeoutError';
209+
}
210+
211+
function timeoutMessage(phase: 'first' | 'idle', ms: number): string {
212+
return phase === 'first'
213+
? `${LLM_STREAM_TIMEOUT_MESSAGE_PREFIX}: no response from the provider within ${ms}ms. ` +
214+
`Raise it with ${LLM_FIRST_EVENT_TIMEOUT_ENV} (milliseconds, 0 disables) or the host's per-model firstEventTimeoutMs.`
215+
: `${LLM_STREAM_TIMEOUT_MESSAGE_PREFIX}: the provider stream was idle for ${ms}ms. ` +
216+
`Raise it with ${LLM_STREAM_IDLE_TIMEOUT_ENV} (milliseconds, 0 disables) or the host's per-model streamIdleTimeoutMs.`;
217+
}
218+
219+
function partialOf(event: AssistantMessageEvent): AssistantMessage | undefined {
220+
if (event.type === 'done') return event.message;
221+
if (event.type === 'error') return event.error;
222+
return event.partial;
223+
}
224+
225+
/** Detach from the provider's mutable partial so a late abort cannot rewrite the reported message. */
226+
function snapshot(partial: AssistantMessage | undefined, model: Model<Api>): AssistantMessage {
227+
return partial ? { ...partial, content: [...partial.content] } : blankAssistant(model);
228+
}
229+
230+
function blankAssistant(model: Model<Api>): AssistantMessage {
231+
return {
232+
role: 'assistant',
233+
content: [],
234+
api: model.api,
235+
provider: model.provider,
236+
model: model.id,
237+
usage: {
238+
input: 0,
239+
output: 0,
240+
cacheRead: 0,
241+
cacheWrite: 0,
242+
totalTokens: 0,
243+
cost: { input: 0, output: 0, cacheRead: 0, cacheWrite: 0, total: 0 },
244+
},
245+
stopReason: 'error',
246+
timestamp: Date.now(),
247+
};
248+
}
249+
250+
function validTimeout(value: number | undefined): number | undefined {
251+
return typeof value === 'number' && Number.isSafeInteger(value) && value >= 0 ? value : undefined;
252+
}
253+
254+
function parseTimeout(raw: string | undefined): number | undefined {
255+
if (raw === undefined || raw.trim() === '' || !/^\d+$/u.test(raw.trim())) return undefined;
256+
return validTimeout(Number(raw.trim()));
257+
}
258+
259+
function readProcessEnv(): Readonly<Record<string, string | undefined>> {
260+
return (globalThis as { process?: { env?: Record<string, string | undefined> } }).process?.env ?? {};
261+
}

‎packages/agent-core/src/pi-turn-runner/llm.ts‎

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import type { Agent, AgentMessage, StreamFn } from '@earendil-works/pi-agent-core';
22
import { streamSimple, type CacheRetention, type SimpleStreamOptions } from '@earendil-works/pi-ai';
33
import { LLM_REQUEST_TIMEOUT_MS } from './defaults.js';
4+
import { resolveLLMStreamTimeouts, withLLMStreamTimeouts } from './llm-stream-timeout.js';
45
import type {
56
PiAfterLlmReplacementCommit,
67
PiBeforeLlmCallAppendMessage,
@@ -27,7 +28,16 @@ export function composeStreamFn(resolved: LLMModelConfig): StreamFn {
2728
? withHeaders(maxTokensWrapped, callerHeaders)
2829
: maxTokensWrapped;
2930
const fetchWrapped = resolved.fetch ? withFetch(headerWrapped, resolved.fetch) : headerWrapped;
30-
return wrapStreamFnWithTimeout(fetchWrapped, LLM_REQUEST_TIMEOUT_MS);
31+
const requestBounded = wrapStreamFnWithTimeout(fetchWrapped, LLM_REQUEST_TIMEOUT_MS);
32+
// Outermost so every physical attempt (each `withLLMRetry` retry calls this
33+
// function again) gets its own first-event / idle watchdog.
34+
return withLLMStreamTimeouts(
35+
requestBounded,
36+
resolveLLMStreamTimeouts({
37+
firstEventTimeoutMs: resolved.firstEventTimeoutMs,
38+
streamIdleTimeoutMs: resolved.streamIdleTimeoutMs,
39+
}),
40+
);
3141
}
3242

3343
export function setLLMHook(agent: Agent, turn: turnState, history: turnHistory): void {

‎packages/agent-core/src/pi-turn-runner/types.ts‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -52,6 +52,19 @@ export interface LLMModelConfig {
5252
*/
5353
hostMaxOutputTokens?: number;
5454
headers?: Record<string, string>;
55+
/**
56+
* Per-attempt wait (ms) for the first provider stream event before the
57+
* request is aborted and reported as a retryable timeout. Absent: the
58+
* `MCODE_LLM_FIRST_EVENT_TIMEOUT_MS` environment value, else
59+
* `LLM_FIRST_EVENT_TIMEOUT_MS`. `0` disables the bound.
60+
*/
61+
firstEventTimeoutMs?: number;
62+
/**
63+
* Per-attempt maximum gap (ms) between provider stream events after the
64+
* first. Absent: `MCODE_LLM_STREAM_IDLE_TIMEOUT_MS`, else
65+
* `LLM_STREAM_IDLE_TIMEOUT_MS`. `0` disables the bound.
66+
*/
67+
streamIdleTimeoutMs?: number;
5568
fetch?: SimpleStreamOptions['fetch'];
5669
/** Provider payload transform for the main assistant response. */
5770
payloadTransform?: SimpleStreamOptions['onPayload'];

0 commit comments

Comments
 (0)