diff --git a/.changeset/remove-false-positive-stall-watchdogs.md b/.changeset/remove-false-positive-stall-watchdogs.md new file mode 100644 index 0000000000..a9ef7764fe --- /dev/null +++ b/.changeset/remove-false-positive-stall-watchdogs.md @@ -0,0 +1,26 @@ +--- +"@agent-native/core": patch +--- + +Remove the in-loop no-progress watchdogs, which were failing healthy runs far more often than they caught wedged ones. + +Two 90s bounds ran for the whole model stream — one on silence between engine frames (`MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS`), one on a tool input whose byte count stopped growing (`ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS`) — plus a zero-byte tool-input restart tripwire. Each inferred a dead stream from the absence of a particular event, and that inference cannot be made on the Anthropic transport: the SDK drops the provider's `ping` keepalives before any consumer sees them (`core/streaming.js`: `if (sse.event === 'ping') continue;`, with no opt-out), so a model composing a large tool argument is indistinguishable from a wedged socket. + +That is normal operation, not an edge case. Only a tool declared for eager input streaming emits anything at all while its arguments are generated, so a long file write or a long structured result is a content-silent window whose length is set by the size of the argument. In one production deployment, 2 of 27 one-shot analyst runs completed; the guards added for reliability were the thing taking it away. + +- `ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS` and its deadline are gone, including the `earliestStartedAt` fallback that anchored the bound to a start time it never advanced past, and the `Math.min` that let it override a demonstrably live stream. +- `MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS` and its deadline are gone. +- The zero-byte restart tripwire is gone (`ACTION_PREPARATION_ZERO_BYTE_RESTART_LIMIT`, `noteZeroByteToolInputStart`, `resetZeroByteToolInputRestart`). +- The two run-lifecycle invariants asserting an ordering between those bounds and the run-manager backstop are gone with them. + +One in-loop bound survives: the pre-first-frame cap on the clamped hosted foreground runtime, where the ~57s platform wall arrives before the engine's own 120s abort could. The first real frame releases it, so long first tokens, long thinking, long tool inputs and long outputs are all past it by construction; off that runtime there is no in-loop deadline at all. + +Real failures keep the bounds that key off evidence rather than absence: the engine's `FIRST_STREAM_EVENT_TIMEOUT_MS` for a stream that opens and never speaks, the run-manager backstop outside the stream, the per-tool execution timeout, the chunk/run budget, and the stale reaper. The trade is explicit: an in-stream wedge after the first frame is now caught by the run budget rather than at 90s, because no clock in the loop could tell it apart from a model writing a large tool call. + +Separately, `runAgentLoop` now takes the caller's real chunk budget instead of re-deriving one. It asked `resolveRunSoftTimeoutMs` for the generic background ceiling (13 min) even when the caller was a background automation, whose budget is its own hard abort minus headroom (10 min − 20s). The per-tool ceiling came out above the run budget, so every per-tool timeout on that path was dead code and the chunk boundary won instead — the exact inversion `RUN_TOOL_TIMEOUT_HEADROOM_MS` exists to prevent, reintroduced by guessing at a number the caller already had. + +Also records liveness forensics when a stale reaper flips a run to `errored`. `stale_run` is the largest terminal outcome on the one-shot automation path and the row said nothing about why — `error_detail` is a fixed sentence for every reap, so a correct reap and a false one were indistinguishable afterwards. The reap now records which of the three stale windows applied, whether the row was redispatchable, time since heartbeat and since progress, whether the in-flight grace was in play, and — the discriminator — how far the heartbeat ran AHEAD of the last real progress. A worker that died takes its heartbeat with it and scores ~0 there; a worker still alive while the agent loop stopped producing scores in the thousands of seconds. Those are opposite bugs that look identical in `agent_runs` today. Diagnostics only: nothing reads it to make a decision, it cannot change whether a row is reaped, and it shares the single `diag_stage` write with the existing recovery outcome rather than overwriting it. + +Also gives the direct-provider engines the total-request deadline they never had, and the resumed rounds the budget they actually have. `createFirstEventAbortController` is now two-stage: the first real frame releases the 120s first-event bound and arms a 14-minute `STREAM_TOTAL_TIMEOUT_MS` on the whole call, mirroring what builder-engine already applies to its own gateway requests. That matters for the runtimes with no outer budget — local dev and self-hosted resolve the soft timeout to `0`, so the deleted watchdog was the only thing standing between them and a socket that wedges after the first frame. It is a total-request bound, not a no-progress bound, so it cannot fire on healthy content-silent generation. The AI SDK path now also reports a deadline abort as an error rather than letting it fall through as a clean `end_turn`, which is a truncated turn reported as a complete one. Alongside it, `runAgentLoopWithResume` hands each round its own `roundTimeoutMs` rather than the whole invocation's, and the main chat handler passes the chunk budget it already resolved into the loop instead of leaving it to re-derive a generic ceiling — the same inversion as the automation case, two call sites over. + +A cancelled request is also no longer classifiable as a timeout. `fireTimeout` recorded its message before checking whether the composed controller had already been aborted, and the parent-abort path left the deadline armed — so a timer firing while the provider settled after a user Stop or a run-budget abort set `didTimeout()`, which is exactly what the engines read to decide a failure was the transport's fault and retryable. The ordering was pre-existing, but harmless while the first frame cleared the timer outright; a deadline that now runs for the whole stream made the window the whole stream. A timeout is recorded only when this controller wins the abort race, parent cancellation clears the deadline, and a frame that lands after a Stop cannot re-arm one. diff --git a/packages/core/src/agent/engine/ai-sdk-engine.ts b/packages/core/src/agent/engine/ai-sdk-engine.ts index 56badf46d6..5d1fbe5a31 100644 --- a/packages/core/src/agent/engine/ai-sdk-engine.ts +++ b/packages/core/src/agent/engine/ai-sdk-engine.ts @@ -32,10 +32,7 @@ import { classifyProviderError, describeErrorWithCauses, } from "./error-detail.js"; -import { - createFirstEventAbortController, - FIRST_STREAM_EVENT_TIMEOUT_MS, -} from "./first-event-timeout.js"; +import { createFirstEventAbortController } from "./first-event-timeout.js"; import { clampThinkingBudgetTokens, resolveMaxOutputTokensForEngine, @@ -533,11 +530,14 @@ class AISDKEngine implements AgentEngine { } // AI SDK surfaces an aborted stream as a graceful `{type: "abort"}` - // part rather than a thrown error, so a first-event timeout would - // otherwise fall through to the normal end_turn completion below. - if (!sawFirstEvent && firstEventAbort.didTimeout()) { + // part rather than a thrown error, so a deadline abort would otherwise + // fall through to the normal end_turn completion below. Not gated on + // `sawFirstEvent`: the total deadline fires mid-stream by definition, and + // reporting that half-delivered turn as a clean end_turn is exactly the + // truncated-run-reported-as-complete failure. + if (firstEventAbort.didTimeout()) { throw new Error( - `Model request produced no stream events within ${FIRST_STREAM_EVENT_TIMEOUT_MS / 1000}s; the connection appears wedged.`, + `${firstEventAbort.timeoutMessage()}; the connection appears wedged.`, ); } diff --git a/packages/core/src/agent/engine/anthropic-engine.ts b/packages/core/src/agent/engine/anthropic-engine.ts index 4ad6e6b86f..e7d66f7ee5 100644 --- a/packages/core/src/agent/engine/anthropic-engine.ts +++ b/packages/core/src/agent/engine/anthropic-engine.ts @@ -25,10 +25,7 @@ import { LLM_MISSING_CREDENTIALS_MESSAGE, } from "./credential-errors.js"; import { describeErrorWithCauses } from "./error-detail.js"; -import { - createFirstEventAbortController, - FIRST_STREAM_EVENT_TIMEOUT_MS, -} from "./first-event-timeout.js"; +import { createFirstEventAbortController } from "./first-event-timeout.js"; import { clampThinkingBudgetTokens, resolveMaxOutputTokensForEngine, @@ -314,12 +311,14 @@ class AnthropicEngine implements AgentEngine { : typeof err?.statusCode === "number" ? err.statusCode : undefined; - // A first-event abort surfaces from the SDK as a generic - // APIUserAbortError ("Request was aborted.") — replace it with a - // message that actually explains what happened. + // A deadline abort surfaces from the SDK as a generic APIUserAbortError + // ("Request was aborted.") — replace it with a message that actually + // explains what happened. Which deadline fired comes from the + // controller: a total-deadline abort is a socket that wedged MID-stream, + // not a connection that never spoke. const rawMessage: string = err?.message ?? String(err); const errorMessage = timedOut - ? `Model request produced no stream events within ${FIRST_STREAM_EVENT_TIMEOUT_MS / 1000}s; the connection appears wedged.` + ? `${firstEventAbort.timeoutMessage()}; the connection appears wedged.` : describeErrorWithCauses(err); // Anthropic SDK APIConnectionError defaults to "Connection error." with // no HTTP status. Tag it so in-run retries and run-level resume treat diff --git a/packages/core/src/agent/engine/first-event-timeout.spec.ts b/packages/core/src/agent/engine/first-event-timeout.spec.ts new file mode 100644 index 0000000000..5d18cade21 --- /dev/null +++ b/packages/core/src/agent/engine/first-event-timeout.spec.ts @@ -0,0 +1,135 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; + +import { + createFirstEventAbortController, + FIRST_STREAM_EVENT_TIMEOUT_MS, + STREAM_TOTAL_TIMEOUT_MS, +} from "./first-event-timeout.js"; + +describe("createFirstEventAbortController", () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + afterEach(() => { + vi.useRealTimers(); + }); + + it("aborts a stream that never produces a first event", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + vi.advanceTimersByTime(FIRST_STREAM_EVENT_TIMEOUT_MS - 1); + expect(abort.signal.aborted).toBe(false); + + vi.advanceTimersByTime(1); + expect(abort.signal.aborted).toBe(true); + expect(abort.didTimeout()).toBe(true); + expect(abort.timeoutMessage()).toContain("no stream events"); + abort.cleanup(); + }); + + // The whole point of removing the in-loop no-progress watchdogs: a model + // composing a large tool input emits nothing a consumer can see, and that is + // healthy. The first event must buy the stream the full total budget. + it("does not bound silence between events once the stream has spoken", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + vi.advanceTimersByTime(1_000); + abort.markFirstEvent(); + + vi.advanceTimersByTime(STREAM_TOTAL_TIMEOUT_MS - 1_001); + expect(abort.signal.aborted).toBe(false); + expect(abort.didTimeout()).toBe(false); + abort.cleanup(); + }); + + // The bound the runtimes with no outer budget (local dev, self-hosted, where + // the soft timeout resolves to 0) depend on: a socket that wedges AFTER the + // first frame must not hang the run forever. + it("aborts a stream that outlives the total deadline, measured from the request start", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + vi.advanceTimersByTime(30_000); + abort.markFirstEvent(); + + vi.advanceTimersByTime(STREAM_TOTAL_TIMEOUT_MS - 30_000); + expect(abort.signal.aborted).toBe(true); + expect(abort.didTimeout()).toBe(true); + expect(abort.timeoutMessage()).toContain("total stream deadline"); + abort.cleanup(); + }); + + it("reports no timeout when the parent aborts", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + parent.abort("user"); + expect(abort.signal.aborted).toBe(true); + expect(abort.didTimeout()).toBe(false); + expect(abort.timeoutMessage()).toBeUndefined(); + abort.cleanup(); + }); + + // A cancelled request is not a failed one. The engines read `didTimeout()` to + // decide a failure was the transport's fault and retryable, so a deadline + // left armed across a Stop would turn a user cancellation or a run-budget + // abort into a resumable provider error. The provider does not necessarily + // settle the moment the signal fires, and `cleanup()` only runs once it does. + it("does not classify a cancelled request as a timeout while the provider settles", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + vi.advanceTimersByTime(5_000); + abort.markFirstEvent(); + vi.advanceTimersByTime(5_000); + parent.abort("user"); + + // The provider takes its time unwinding, so `cleanup()` has not run yet. + vi.advanceTimersByTime(STREAM_TOTAL_TIMEOUT_MS * 2); + + expect(abort.didTimeout()).toBe(false); + expect(abort.timeoutMessage()).toBeUndefined(); + abort.cleanup(); + }); + + it("does not classify a pre-first-event cancellation as a timeout", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + parent.abort("run_timeout"); + vi.advanceTimersByTime(FIRST_STREAM_EVENT_TIMEOUT_MS * 2); + + expect(abort.didTimeout()).toBe(false); + expect(abort.timeoutMessage()).toBeUndefined(); + abort.cleanup(); + }); + + // A frame already in flight when the Stop lands must not re-arm a deadline + // on a request that is over. + it("does not re-arm a deadline for a frame that lands after cancellation", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + parent.abort("user"); + abort.markFirstEvent(); + vi.advanceTimersByTime(STREAM_TOTAL_TIMEOUT_MS * 2); + + expect(abort.didTimeout()).toBe(false); + expect(abort.timeoutMessage()).toBeUndefined(); + abort.cleanup(); + }); + + it("stops both deadlines on cleanup", () => { + const parent = new AbortController(); + const abort = createFirstEventAbortController(parent.signal); + + abort.markFirstEvent(); + abort.cleanup(); + + vi.advanceTimersByTime(STREAM_TOTAL_TIMEOUT_MS * 2); + expect(abort.signal.aborted).toBe(false); + expect(abort.didTimeout()).toBe(false); + }); +}); diff --git a/packages/core/src/agent/engine/first-event-timeout.ts b/packages/core/src/agent/engine/first-event-timeout.ts index dc599327fa..9a657cb937 100644 --- a/packages/core/src/agent/engine/first-event-timeout.ts +++ b/packages/core/src/agent/engine/first-event-timeout.ts @@ -1,56 +1,97 @@ /** - * Shared "first stream event" deadline for model-request engines. + * Shared stream deadlines for model-request engines. * - * A request that connects successfully but then streams zero events means the - * transport or gateway is wedged, not slow — real models (including deep - * thinking ones) emit their first event within seconds. Bounding this window - * separately from any total-request deadline turns a silent multi-minute hang - * into a fast abort-and-retry. + * Two bounds, both keyed off facts the transport can actually establish: * - * AUDIENCE: direct `engine.stream()` callers — `completeText`, voice - * transcription, sentiment, evals, observational memory. It is EXPECTED to be - * shadowed inside `runAgentLoop`, whose own `MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS` - * (90s) races the same first frame and always wins. That does not make it - * redundant: `completeText` takes `timeoutMs` as optional, so a caller that - * omits one has no other bound between it and an unbounded hang. Do not - * "clean it up" as unreachable — check the non-loop callers first. + * - FIRST: a request that connects and then streams zero events means the + * transport or gateway is wedged, not slow — real models (including deep + * thinking ones) emit their first event within seconds. + * - TOTAL: the whole request, first event or not, cannot outlive the largest + * budget any caller runs inside. + * + * AUDIENCE: every `engine.stream()` caller, `runAgentLoop` INCLUDED. The first + * bound used to be described as shadowed inside the loop by a 90s in-loop + * watchdog that "always wins"; that watchdog is gone (see + * run-lifecycle-invariants.ts), so these are now the PRIMARY bounds on a model + * call that wedges. They survive that deletion because neither infers death + * from the ABSENCE of a particular event mid-generation — the fact the removed + * watchdogs got wrong, since the Anthropic SDK drops the provider's `ping` + * keepalives before any consumer sees them. Do not "clean them up" as + * redundant, and do not add a no-progress bound back beside them. */ export const FIRST_STREAM_EVENT_TIMEOUT_MS = 120_000; +/** + * Ceiling on one model call end to end, measured from request start. + * + * Sized so it can never preempt healthy work: the largest chunk any caller runs + * inside is the ~13-minute background soft timeout, and a hosted run is bounded + * by its own chunk long before this. It exists for the runtimes that have no + * outer budget at all — local dev and self-hosted resolve the soft timeout to + * `0`, so without this a socket that wedges AFTER the first frame leaves the + * run pending forever. Mirrors the ceiling builder-engine already applies to + * its own gateway requests, for the engines that talk to a provider directly. + */ +export const STREAM_TOTAL_TIMEOUT_MS = 14 * 60_000; + export interface FirstEventAbortController { readonly signal: AbortSignal; /** Idempotent. Call once the first real (non-keepalive) stream event arrives. */ markFirstEvent: () => void; didTimeout: () => boolean; + /** + * Which deadline fired, phrased for the user, or `undefined` if none did. + * Callers must not assume a timeout is the first-event one — after + * `markFirstEvent()` a timeout means the total deadline, and reporting the + * wrong one describes a wedged mid-stream socket as a connection that never + * spoke. + */ + timeoutMessage: () => string | undefined; cleanup: () => void; } /** - * Layer a first-event deadline on top of a caller's AbortSignal. Aborts if - * `markFirstEvent()` is not called within `FIRST_STREAM_EVENT_TIMEOUT_MS`. - * Has no opinion on a total-request deadline — callers that need one (e.g. - * builder-engine's flat gateway timeout) compose their own on top. + * Layer the two deadlines above on top of a caller's AbortSignal. Aborts if + * `markFirstEvent()` is not called within `FIRST_STREAM_EVENT_TIMEOUT_MS`, and + * again if the whole request outlives `STREAM_TOTAL_TIMEOUT_MS`. Callers that + * need a TIGHTER total deadline (e.g. builder-engine's flat gateway timeout) + * compose their own on top. */ export function createFirstEventAbortController( parentSignal: AbortSignal, ): FirstEventAbortController { const controller = new AbortController(); - let timedOut = false; + const startedAt = Date.now(); + let timeoutMessage: string | undefined; let firstEventSeen = false; const abortFromParent = () => { + // Drop the outstanding deadline too. A parent abort ends this request, and + // the provider can take a moment to settle afterwards — a timer still + // armed through that window fires into an already-cancelled request and + // relabels a user Stop or a run-budget abort as a retryable provider + // failure. That window used to be small because the first frame cleared + // the timer outright; now that a deadline runs for the whole stream, it is + // the whole stream. + clearTimeout(timeout); if (!controller.signal.aborted) controller.abort(parentSignal.reason); }; - const timeout = setTimeout(() => { - timedOut = true; - if (!controller.signal.aborted) { - controller.abort( - new Error( - `Model request produced no stream events within ${FIRST_STREAM_EVENT_TIMEOUT_MS / 1000}s`, - ), - ); - } + const fireTimeout = (message: string) => { + // Record a timeout ONLY when this controller wins the abort race. Setting + // the message first and checking `aborted` after made a deadline that + // merely fired into an already-aborted controller indistinguishable from + // one that caused the abort — and `didTimeout()` is what the engines read + // to decide a failure was the transport's fault and worth retrying. + if (controller.signal.aborted) return; + timeoutMessage = message; + controller.abort(new Error(message)); + }; + + let timeout = setTimeout(() => { + fireTimeout( + `Model request produced no stream events within ${FIRST_STREAM_EVENT_TIMEOUT_MS / 1000}s`, + ); }, FIRST_STREAM_EVENT_TIMEOUT_MS); if (parentSignal.aborted) abortFromParent(); @@ -59,11 +100,24 @@ export function createFirstEventAbortController( return { signal: controller.signal, markFirstEvent: () => { - if (firstEventSeen) return; + // `aborted` subsumes the timeout check — `fireTimeout` only records a + // message when it aborts — and also covers the parent-abort case, so a + // frame processed after a Stop cannot re-arm a deadline on a dead + // request. + if (firstEventSeen || controller.signal.aborted) return; firstEventSeen = true; clearTimeout(timeout); + timeout = setTimeout( + () => { + fireTimeout( + `Model request exceeded the ${STREAM_TOTAL_TIMEOUT_MS / 60_000}-minute total stream deadline`, + ); + }, + Math.max(0, STREAM_TOTAL_TIMEOUT_MS - (Date.now() - startedAt)), + ); }, - didTimeout: () => timedOut, + didTimeout: () => timeoutMessage !== undefined, + timeoutMessage: () => timeoutMessage, cleanup: () => { clearTimeout(timeout); parentSignal.removeEventListener("abort", abortFromParent); diff --git a/packages/core/src/agent/production-agent.spec.ts b/packages/core/src/agent/production-agent.spec.ts index b2e717854f..4b5631184f 100644 --- a/packages/core/src/agent/production-agent.spec.ts +++ b/packages/core/src/agent/production-agent.spec.ts @@ -2606,7 +2606,17 @@ describe("runAgentLoop", () => { ); }); - it("checkpoints when action input preparation stops streaming bytes", async () => { + it("does NOT checkpoint when a tool input goes quiet — that is a big argument, not a stall", async () => { + // THE REGRESSION THIS FILE USED TO ASSERT THE OPPOSITE OF. + // + // Only a tool declared for eager input streaming emits `input_json_delta` + // while its arguments are generated. Everything else produces + // `tool-input-start` and then NOTHING until the whole argument blob is + // ready — for a large file or a long structured result that is minutes of + // legitimate silence. The retired action-preparation watchdog read the + // stalled byte counter as a dead stream and cut the turn off at 90s; on the + // Anthropic transport it could not have known better, because the SDK drops + // the provider pings that would have proved liveness. let now = 1_000_000; const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); const engine: AgentEngine = { @@ -2627,9 +2637,10 @@ describe("runAgentLoop", () => { id: "tool-edit", name: "edit-design", }; - now += 91_000; + // Five minutes composing the argument, not one byte forwarded. + now += 5 * 60_000; yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; + yield { type: "text-delta", text: "the turn continues" }; }, }; const events: AgentChatEvent[] = []; @@ -2651,109 +2662,28 @@ describe("runAgentLoop", () => { dateNow.mockRestore(); } + // The preparation activity still reaches the UI — the user sees progress. expect(events).toContainEqual({ type: "activity", label: "Preparing edit-design action", tool: "edit-design", id: "tool-edit", }); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual({ type: "stream_keepalive" }); - expect(events).not.toContainEqual({ type: "done" }); + // Nothing cut the turn off DURING the quiet stretch, and the text that + // followed it still reached the client. expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), + expect.objectContaining({ type: "auto_continue", reason: "no_progress" }), ); - }); - - it("continues main chat internally after a no-progress action preparation checkpoint", async () => { - let now = 1_000_000; - let attempts = 0; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - attempts++; - if (attempts === 1) { - yield { - type: "tool-input-start", - id: "tool-edit", - name: "edit-design", - }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - return; - } - yield { type: "text-delta", text: "continued" }; - yield { - type: "assistant-content", - parts: [{ type: "text" as const, text: "continued" }], - }; - yield { type: "stop", reason: "end_turn" }; - }, - }; - const events: AgentChatEvent[] = []; - const guard = vi.fn(() => null); - const messages = [ - { - role: "user" as const, - content: [{ type: "text" as const, text: "go" }], - }, - ]; - - try { - await runAgentLoopWithMainChatInternalContinuations({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages, - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - finalResponseGuard: guard, - }); - } finally { - dateNow.mockRestore(); - } - - expect(attempts).toBe(2); - const continuationText = messages - .map((message) => - message.content[0]?.type === "text" ? message.content[0].text : "", - ) - .find((text) => text.includes(AGENT_INTERNAL_CONTINUE_PROMPT)); - expect(continuationText).toContain(AGENT_INTERNAL_CONTINUE_PROMPT); - expect(continuationText).toContain( - "preparing the `edit-design` action input", + expect(events).toContainEqual( + expect.objectContaining({ type: "text", text: "the turn continues" }), ); - expect(events).toContainEqual({ type: "clear" }); - expect(events).toContainEqual({ type: "text", text: "continued" }); - expect(events).toContainEqual({ type: "done" }); - expect(guard).toHaveBeenCalledTimes(1); - expect(guard.mock.calls[0]?.[0].requestText).toBe("go"); - expect(events).not.toContainEqual({ + // The stream still ends with an undelivered tool input, which is a real + // truncation and keeps its own boundary — that guard reads the STREAM + // ENDING, not a clock, so it cannot fire on slow work. + expect(events.at(-1)).toEqual({ type: "auto_continue", - reason: "no_progress", + reason: "stream_ended", }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); }); it("auto-continues when a stream ends with a partial action input", async () => { @@ -2934,31 +2864,23 @@ describe("runAgentLoop", () => { expect(events).not.toContainEqual({ type: "done" }); }); - it("checkpoints when zero-byte action input preparation goes silent", async () => { + it("does NOT checkpoint a zero-byte tool input that stays quiet", async () => { + // The zero-byte restart tripwire is gone with the rest of the + // action-preparation machinery. A tool input announced with no bytes yet is + // the ORDINARY opening of a non-eagerly-streamed tool call, not evidence of + // a wedge — and on this transport nothing distinguishes the two, because + // the provider's pings never reach us. vi.useFakeTimers({ now: 1_000_000 }); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-delta", - id: "tool-edit", - name: "edit-design", - text: "", - }; - await new Promise(() => {}); + const engine = abortableHangingEngine([ + { + type: "tool-input-delta", + id: "tool-edit", + name: "edit-design", + text: "", }, - }; + ]); const events: AgentChatEvent[] = []; + const controller = new AbortController(); try { const run = runAgentLoop({ @@ -2971,31 +2893,19 @@ describe("runAgentLoop", () => { "edit-design": actionEntry({ readOnly: false }), }, send: (event) => events.push(event), - signal: new AbortController().signal, - }); - - await vi.advanceTimersByTimeAsync(0); - expect(events).toContainEqual({ - type: "activity", - label: "Preparing edit-design action", - tool: "edit-design", - id: "tool-edit", - progressBytes: 0, + signal: controller.signal, }); + void run.catch(() => undefined); - await vi.advanceTimersByTimeAsync(90_000); - await run; + await vi.advanceTimersByTimeAsync(10 * 60_000); + expect(events).not.toContainEqual( + expect.objectContaining({ type: "auto_continue" }), + ); + controller.abort(); + await run.catch(() => undefined); } finally { vi.useRealTimers(); } - - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); }); it("clears the action-preparation timeout when the stream rejects", async () => { @@ -3102,6 +3012,43 @@ describe("runAgentLoop", () => { }, }); + /** + * Hangs like `hangingFirstEventEngine`, but RETURNS when the caller aborts. + * + * Tests that assert "no bound fires" cannot let the run promise stay pending: + * with nothing left to settle it, the vitest worker is torn down with the + * fork still live and the whole FILE fails with "Worker exited unexpectedly" + * even though every test passed. An engine that ignores `abortSignal` is also + * simply not a realistic one. + * + * `prelude` events are yielded first, for the cases that need the stream to + * have produced something before it goes quiet. + */ + const abortableHangingEngine = ( + prelude: EngineEvent[] = [], + ): AgentEngine => ({ + name: "test", + label: "Test", + defaultModel: "test-model", + supportedModels: ["test-model"], + capabilities: { + thinking: false, + promptCaching: false, + vision: false, + computerUse: false, + parallelToolCalls: true, + }, + async *stream(opts): AsyncIterable { + for (const event of prelude) yield event; + await new Promise((resolve) => { + if (opts.abortSignal.aborted) return resolve(); + opts.abortSignal.addEventListener("abort", () => resolve(), { + once: true, + }); + }); + }, + }); + const modelStreamBracket = (events: AgentChatEvent[]) => events.filter((event) => event.type === "model_stream"); @@ -3234,110 +3181,88 @@ describe("runAgentLoop", () => { }); }); - it("FIX 2: a hung FIRST model event keeps the full 90s window on a NON-HOSTED runtime (local dev / self-hosted)", async () => { - // All hosted markers cleared — resolveRunSoftTimeoutMs resolves to 0 - // here (no soft-timeout regime, no platform wall), so a genuinely slow - // first token (large local contexts, slow local providers) must NOT be - // chopped at 25s. + it("a hung FIRST model event has NO in-loop bound on a NON-HOSTED runtime (local dev / self-hosted)", async () => { + // All hosted markers cleared — no soft-timeout regime, no platform wall. + // The in-loop watchdogs are gone entirely; a hung stream is the engine's + // own `FIRST_STREAM_EVENT_TIMEOUT_MS` to catch, not this loop's. const restoreEnv = snapshotAndClearRuntimePredicateEnv(); vi.useFakeTimers({ now: 1_000_000 }); const events: AgentChatEvent[] = []; + const controller = new AbortController(); try { const run = runAgentLoop({ - engine: hangingFirstEventEngine(), + engine: abortableHangingEngine(), model: "test-model", systemPrompt: "system", tools: [], messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], actions: {}, send: (event) => events.push(event), - signal: new AbortController().signal, + signal: controller.signal, }); + void run.catch(() => undefined); - // Past the 25s cap — a non-hosted runtime must be unaffected by it. - await vi.advanceTimersByTimeAsync(26_000); + // Well past both retired 90s watchdogs: nothing may checkpoint here. + await vi.advanceTimersByTimeAsync(10 * 60_000); expect(events).toEqual([{ type: "model_stream", status: "start" }]); - - // The normal 90s in-loop watchdog still applies and eventually fires. - await vi.advanceTimersByTimeAsync(90_000 - 26_000); - await run; + controller.abort(); + await run.catch(() => undefined); } finally { vi.useRealTimers(); restoreEnv(); } - - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); }); - it("FIX 2: a hung FIRST model event does NOT fire early when proven to be running inside a background function", async () => { + it("a hung FIRST model event has NO in-loop bound inside a background function", async () => { const restoreEnv = snapshotAndClearRuntimePredicateEnv(); // Hosted AND proven background-function runtime (`-background` Lambda - // name) — the 15-min budget applies, so the cap must stay off. + // name) — the 15-min budget applies, so no in-loop cap may arm. process.env.AWS_LAMBDA_FUNCTION_NAME = "server-agent-background"; vi.useFakeTimers({ now: 1_000_000 }); const events: AgentChatEvent[] = []; + const controller = new AbortController(); try { const run = runAgentLoop({ - engine: hangingFirstEventEngine(), + engine: abortableHangingEngine(), model: "test-model", systemPrompt: "system", tools: [], messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], actions: {}, send: (event) => events.push(event), - signal: new AbortController().signal, + signal: controller.signal, }); + void run.catch(() => undefined); - // Past the 25s foreground cap — a proven background-function worker - // must be unaffected by it. - await vi.advanceTimersByTimeAsync(26_000); + await vi.advanceTimersByTimeAsync(10 * 60_000); expect(events).toEqual([{ type: "model_stream", status: "start" }]); - - // The normal 90s watchdog still applies and eventually fires. - await vi.advanceTimersByTimeAsync(90_000 - 26_000); - await run; + controller.abort(); + await run.catch(() => undefined); } finally { vi.useRealTimers(); restoreEnv(); } - - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); }); - it("FIX 2: a gap AFTER the first event keeps the normal 90s window on the HOSTED foreground runtime", async () => { + it("a gap AFTER the first event is NEVER bounded in-loop, even on hosted foreground", async () => { + // THE CASE THE RETIRED WATCHDOGS GOT WRONG. Once a model call has produced + // anything, a silent stretch is normal work — extended thinking, or a tool + // whose input is not eagerly streamed and so emits nothing at all while the + // provider composes its arguments. The Anthropic SDK swallows the pings + // that would prove liveness, so this loop cannot tell slow from wedged and + // must not try: it is the run budget's job to bound cost, not this one's. const restoreEnv = snapshotAndClearRuntimePredicateEnv(); process.env.AWS_LAMBDA_FUNCTION_NAME = "server"; vi.useFakeTimers({ now: 1_000_000 }); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - // A real first event arrives promptly... - yield { type: "text-delta", text: "thinking" }; - // ...then the stream goes silent. Only the FIRST await on a fresh - // model call is capped at 25s — this gap must ride the normal 90s - // watchdog even though it also exceeds 25s. - await new Promise(() => {}); - }, - }; + // A real first event arrives promptly, releasing the only remaining + // in-loop cap, then a long content-silent stretch which must survive. + const engine = abortableHangingEngine([ + { type: "text-delta", text: "thinking" }, + ]); const events: AgentChatEvent[] = []; + const controller = new AbortController(); try { const run = runAgentLoop({ @@ -3348,25 +3273,22 @@ describe("runAgentLoop", () => { messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], actions: {}, send: (event) => events.push(event), - signal: new AbortController().signal, + signal: controller.signal, }); + void run.catch(() => undefined); - await vi.advanceTimersByTimeAsync(26_000); + // Ten minutes of content silence: a large tool input is exactly this + // shape, and nothing here may cut it off. + await vi.advanceTimersByTimeAsync(10 * 60_000); expect(events).not.toContainEqual( expect.objectContaining({ type: "auto_continue" }), ); - - await vi.advanceTimersByTimeAsync(90_000 - 26_000); - await run; + controller.abort(); + await run.catch(() => undefined); } finally { vi.useRealTimers(); restoreEnv(); } - - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); }); it("FIX 2: a stream of only gateway keepalives still trips the 25s cap on the HOSTED foreground runtime", async () => { @@ -3611,10 +3533,9 @@ describe("runAgentLoop", () => { expect(streamCalls).toBe(1); }); - it("closes the event stream after an action-preparation stall", async () => { + it("keeps a model stream alive when non-heartbeat events continue", async () => { let now = 1_000_000; const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const returnSpy = vi.fn(async () => ({ done: true, value: undefined })); const engine: AgentEngine = { name: "test", label: "Test", @@ -3627,33 +3548,18 @@ describe("runAgentLoop", () => { computerUse: false, parallelToolCalls: true, }, - stream(): AsyncIterable { - let step = 0; - return { - [Symbol.asyncIterator]() { - return { - async next() { - if (step === 0) { - step += 1; - return { - done: false, - value: { - type: "tool-input-start", - id: "tool-edit", - name: "edit-design", - }, - }; - } - now += 91_000; - return { - done: false, - value: { type: "gateway-heartbeat" }, - }; - }, - return: returnSpy, - }; - }, + async *stream(): AsyncIterable { + now += 45_000; + yield { type: "gateway-heartbeat" }; + now += 44_000; + yield { type: "text-delta", text: "still alive" }; + now += 89_000; + yield { type: "gateway-heartbeat" }; + yield { + type: "assistant-content", + parts: [{ type: "text" as const, text: "still alive" }], }; + yield { type: "stop", reason: "end_turn" }; }, }; const events: AgentChatEvent[] = []; @@ -3665,9 +3571,7 @@ describe("runAgentLoop", () => { systemPrompt: "system", tools: [], messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, + actions: {}, send: (event) => events.push(event), signal: new AbortController().signal, }); @@ -3675,18 +3579,17 @@ describe("runAgentLoop", () => { dateNow.mockRestore(); } - expect(returnSpy).toHaveBeenCalledTimes(1); - expect(events.at(-1)).toEqual({ + expect(events).toContainEqual({ type: "text", text: "still alive" }); + expect(events).toContainEqual({ type: "done" }); + expect(events).not.toContainEqual({ type: "auto_continue", reason: "no_progress", }); - expect(events).not.toContainEqual({ type: "stream_keepalive" }); }); - it("checkpoints when the model stream goes keepalive-only after a tool result", async () => { + it("keeps a fresh action-input id streaming after an abandoned zero-byte id", async () => { let now = 1_000_000; const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - let streamCount = 0; const engine: AgentEngine = { name: "test", label: "Test", @@ -3700,25 +3603,31 @@ describe("runAgentLoop", () => { parallelToolCalls: true, }, async *stream(): AsyncIterable { - streamCount += 1; - if (streamCount === 1) { - yield { - type: "assistant-content", - parts: [ - { - type: "tool-call" as const, - id: "tool-snapshot", - name: "get-design-snapshot", - input: { designId: "design-1", fileId: "file-1" }, - }, - ], - }; - yield { type: "stop", reason: "tool_use" }; - return; - } - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; + yield { + type: "tool-input-delta", + id: "tool-edit-abandoned", + name: "edit-design", + text: "", + }; + now += 45_000; + yield { + type: "tool-input-delta", + id: "tool-edit-replacement", + name: "edit-design", + text: '{"replacementContent":"first bytes', + }; + now += 46_000; + yield { + type: "tool-input-delta", + id: "tool-edit-replacement", + name: "edit-design", + text: ' and still streaming"}', + }; + yield { + type: "assistant-content", + parts: [{ type: "text" as const, text: "done" }], + }; + yield { type: "stop", reason: "end_turn" }; }, }; const events: AgentChatEvent[] = []; @@ -3731,7 +3640,7 @@ describe("runAgentLoop", () => { tools: [], messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], actions: { - "get-design-snapshot": actionEntry({ readOnly: true }), + "edit-design": actionEntry({ readOnly: false }), }, send: (event) => events.push(event), signal: new AbortController().signal, @@ -3742,21 +3651,20 @@ describe("runAgentLoop", () => { expect(events).toContainEqual( expect.objectContaining({ - type: "tool_done", - tool: "get-design-snapshot", + type: "activity", + tool: "edit-design", + id: "tool-edit-replacement", + progressBytes: 56, }), ); - expect(events.at(-1)).toEqual({ + expect(events).not.toContainEqual({ type: "auto_continue", reason: "no_progress", }); - expect(events).not.toContainEqual({ type: "stream_keepalive" }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); + expect(events.at(-1)).toEqual({ type: "done" }); }); - it("keeps a model stream alive when non-heartbeat events continue", async () => { + it("keeps a fresh read-only input id streaming after an abandoned zero-byte id", async () => { let now = 1_000_000; const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); const engine: AgentEngine = { @@ -3772,676 +3680,11 @@ describe("runAgentLoop", () => { parallelToolCalls: true, }, async *stream(): AsyncIterable { - now += 45_000; - yield { type: "gateway-heartbeat" }; - now += 44_000; - yield { type: "text-delta", text: "still alive" }; - now += 89_000; - yield { type: "gateway-heartbeat" }; yield { - type: "assistant-content", - parts: [{ type: "text" as const, text: "still alive" }], - }; - yield { type: "stop", reason: "end_turn" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: {}, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual({ type: "text", text: "still alive" }); - expect(events).toContainEqual({ type: "done" }); - expect(events).not.toContainEqual({ - type: "auto_continue", - reason: "no_progress", - }); - }); - - it("keeps tracking a stalled action input across assistant snapshots", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-start", - id: "tool-edit", - name: "edit-design", - }; - yield { - type: "assistant-content", - parts: [{ type: "text", text: "previous assistant text snapshot" }], - }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual({ - type: "activity", - label: "Preparing edit-design action", - tool: "edit-design", - id: "tool-edit", - }); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual({ type: "stream_keepalive" }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - }); - - it("tracks a zero-byte action input delta without a start event", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { type: "gateway-heartbeat" }; - now += 10_000; - yield { - type: "tool-input-delta", - id: "tool-edit", - name: "edit-design", - text: "", - }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual({ - type: "activity", - label: "Preparing edit-design action", - tool: "edit-design", - id: "tool-edit", - progressBytes: 0, - }); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); - }); - - it("keeps tracking stalled action input after a prepared tool-call snapshot", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-start", - id: "tool-edit", - name: "edit-design", - }; - now += 1_600; - yield { - type: "tool-input-delta", - id: "tool-edit", - text: '{"designId":"design-1"', - }; - yield { - type: "assistant-content", - parts: [ - { - type: "tool-call", - id: "tool-edit", - name: "edit-design", - input: { designId: "design-1" }, - }, - ], - }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual({ - type: "activity", - label: "Preparing edit-design action", - tool: "edit-design", - id: "tool-edit", - progressBytes: 22, - }); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual({ type: "stream_keepalive" }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); - }); - - it("checkpoints a stalled action input before accepting a delayed progress event", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-start", - id: "tool-edit", - name: "edit-design", - }; - now += 91_000; - yield { - type: "tool-input-delta", - id: "tool-edit", - text: "delayed bytes", - }; - yield { - type: "assistant-content", - parts: [ - { - type: "tool-call" as const, - id: "tool-edit", - name: "edit-design", - input: { replacementContent: "late" }, - }, - ], - }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual({ - type: "activity", - label: "Preparing edit-design action", - tool: "edit-design", - id: "tool-edit", - }); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ - type: "activity", - progressBytes: expect.any(Number), - }), - ); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); - }); - - it("checkpoints repeated zero-byte action input restarts", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-start", - id: "tool-edit-a", - name: "edit-design", - }; - yield { - type: "assistant-content", - parts: [], - }; - now += 45_000; - yield { - type: "tool-input-start", - id: "tool-edit-b", - name: "edit-design", - }; - yield { - type: "assistant-content", - parts: [], - }; - now += 46_000; - yield { - type: "tool-input-start", - id: "tool-edit-c", - name: "edit-design", - }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect( - events.filter( - (event) => event.type === "activity" && event.tool === "edit-design", - ).length, - ).toBeGreaterThanOrEqual(2); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); - }); - - it("checkpoints repeated zero-byte action input deltas with fresh ids", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-delta", - id: "tool-edit-a", - name: "edit-design", - text: "", - }; - yield { type: "gateway-heartbeat" }; - now += 45_000; - yield { - type: "tool-input-delta", - id: "tool-edit-b", - name: "edit-design", - text: "", - }; - yield { type: "gateway-heartbeat" }; - now += 46_000; - yield { - type: "tool-input-delta", - id: "tool-edit-c", - name: "edit-design", - text: "", - }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect( - events.filter( - (event) => - event.type === "activity" && - event.tool === "edit-design" && - event.progressBytes === 0, - ).length, - ).toBeGreaterThanOrEqual(2); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); - }); - - it("does not treat fresh zero-byte action input ids as progress", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-delta", - id: "tool-edit-a", - name: "edit-design", - text: "", - }; - now += 45_000; - yield { - type: "tool-input-delta", - id: "tool-edit-b", - name: "edit-design", - text: "", - }; - now += 44_000; - yield { - type: "tool-input-delta", - id: "tool-edit-c", - name: "edit-design", - text: "", - }; - now += 2_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect( - events.filter( - (event) => - event.type === "activity" && - event.tool === "edit-design" && - event.progressBytes === 0, - ).length, - ).toBeGreaterThanOrEqual(2); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "tool_start" }), - ); - }); - - it("keeps a fresh action-input id streaming after an abandoned zero-byte id", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-delta", - id: "tool-edit-abandoned", - name: "edit-design", - text: "", - }; - now += 45_000; - yield { - type: "tool-input-delta", - id: "tool-edit-replacement", - name: "edit-design", - text: '{"replacementContent":"first bytes', - }; - now += 46_000; - yield { - type: "tool-input-delta", - id: "tool-edit-replacement", - name: "edit-design", - text: ' and still streaming"}', - }; - yield { - type: "assistant-content", - parts: [{ type: "text" as const, text: "done" }], - }; - yield { type: "stop", reason: "end_turn" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual( - expect.objectContaining({ - type: "activity", - tool: "edit-design", - id: "tool-edit-replacement", - progressBytes: 56, - }), - ); - expect(events).not.toContainEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events.at(-1)).toEqual({ type: "done" }); - }); - - it("keeps a fresh read-only input id streaming after an abandoned zero-byte id", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-delta", - id: "search-abandoned", - name: "search", - text: "", + type: "tool-input-delta", + id: "search-abandoned", + name: "search", + text: "", }; now += 45_000; yield { @@ -4574,272 +3817,6 @@ describe("runAgentLoop", () => { expect(events.at(-1)).toEqual({ type: "done" }); }); - it("keeps parallel-safe same-action input stalls tracked while a sibling streams", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-start", - id: "parallel-search-a", - name: "search", - }; - now += 45_000; - yield { - type: "tool-input-start", - id: "parallel-search-b", - name: "search", - }; - now += 2_000; - yield { - type: "tool-input-delta", - id: "parallel-search-b", - name: "search", - text: '{"query":"healthy sibling', - }; - now += 44_000; - yield { - type: "tool-input-delta", - id: "parallel-search-b", - name: "search", - text: ' still streaming"}', - }; - yield { type: "text-delta", text: "still preparing" }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - search: actionEntry({ readOnly: false, parallelSafe: true }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual( - expect.objectContaining({ - type: "activity", - tool: "search", - id: "parallel-search-b", - progressBytes: 25, - }), - ); - expect(events).toContainEqual( - expect.objectContaining({ type: "text", text: "still preparing" }), - ); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - }); - - it("keeps delta-only same-action input progress alive while a sibling is silent", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-delta", - id: "delta-search-a", - name: "search", - text: "", - }; - now += 45_000; - yield { - type: "tool-input-delta", - id: "delta-search-b", - name: "search", - text: "", - }; - now += 2_000; - yield { - type: "tool-input-delta", - id: "delta-search-c", - name: "search", - text: '{"query":"healthy sibling', - }; - now += 44_000; - yield { - type: "tool-input-delta", - id: "delta-search-c", - name: "search", - text: ' still streaming"}', - }; - yield { type: "text-delta", text: "still preparing" }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { type: "text-delta", text: "should not continue" }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - search: actionEntry({ readOnly: true }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual( - expect.objectContaining({ - type: "activity", - tool: "search", - id: "delta-search-c", - progressBytes: 25, - }), - ); - expect(events).toContainEqual( - expect.objectContaining({ type: "text", text: "still preparing" }), - ); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - }); - - it("tracks action-preparation stalls for multiple in-flight tool inputs", async () => { - let now = 1_000_000; - const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); - const engine: AgentEngine = { - name: "test", - label: "Test", - defaultModel: "test-model", - supportedModels: ["test-model"], - capabilities: { - thinking: false, - promptCaching: false, - vision: false, - computerUse: false, - parallelToolCalls: true, - }, - async *stream(): AsyncIterable { - yield { - type: "tool-input-start", - id: "tool-a", - name: "edit-design", - }; - now += 30_000; - yield { - type: "tool-input-start", - id: "tool-b", - name: "generate-design", - }; - now += 30_000; - yield { - type: "tool-input-delta", - id: "tool-b", - text: "healthy", - }; - now += 31_000; - yield { - type: "tool-input-delta", - id: "tool-b", - text: "still healthy", - }; - yield { type: "text-delta", text: "still preparing" }; - now += 91_000; - yield { type: "gateway-heartbeat" }; - yield { - type: "text-delta", - text: "should not continue", - }; - }, - }; - const events: AgentChatEvent[] = []; - - try { - await runAgentLoop({ - engine, - model: "test-model", - systemPrompt: "system", - tools: [], - messages: [{ role: "user", content: [{ type: "text", text: "go" }] }], - actions: { - "edit-design": actionEntry({ readOnly: false }), - "generate-design": actionEntry({ readOnly: false }), - }, - send: (event) => events.push(event), - signal: new AbortController().signal, - }); - } finally { - dateNow.mockRestore(); - } - - expect(events).toContainEqual({ - type: "activity", - label: "Preparing edit-design action", - tool: "edit-design", - id: "tool-a", - }); - expect(events).toContainEqual({ - type: "activity", - label: "Preparing generate-design action", - tool: "generate-design", - id: "tool-b", - }); - expect(events).toContainEqual( - expect.objectContaining({ type: "text", text: "still preparing" }), - ); - expect(events.at(-1)).toEqual({ - type: "auto_continue", - reason: "no_progress", - }); - expect(events).not.toContainEqual( - expect.objectContaining({ type: "text", text: "should not continue" }), - ); - }); - it("keeps assembling a large action input while bytes keep streaming", async () => { let now = 1_000_000; const dateNow = vi.spyOn(Date, "now").mockImplementation(() => now); diff --git a/packages/core/src/agent/production-agent.ts b/packages/core/src/agent/production-agent.ts index 18e4d309af..fd6a22e156 100644 --- a/packages/core/src/agent/production-agent.ts +++ b/packages/core/src/agent/production-agent.ts @@ -20,11 +20,9 @@ import { stripUnsupportedSchemaKeywords, } from "../action.js"; import { - ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS, MAX_BACKGROUND_RUN_CONTINUATIONS, MAX_CONSECUTIVE_NO_PROGRESS_CONTINUATIONS, MAX_TURN_WALL_CLOCK_MS, - MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS, } from "../app-config/run-lifecycle-invariants.js"; import { readAppState } from "../application-state/script-helpers.js"; import { isReadOnlyShellCommand } from "../coding-tools/index.js"; @@ -1424,7 +1422,6 @@ function maxRetriesForError(err: unknown): number { return MAX_RETRIES; } const TOOL_INPUT_ACTIVITY_INTERVAL_MS = 1500; -const ACTION_PREPARATION_ZERO_BYTE_RESTART_LIMIT = 2; /** * How long an attempt must have run before its retry is worth narrating. * @@ -4589,6 +4586,14 @@ export async function runAgentLoop(opts: { * App-level default limits applied to every tool call unless the individual * ActionEntry overrides them with its own timeoutMs / maxResultChars. */ + /** + * The chunk's REAL soft-timeout budget, when the caller has one. + * + * Only `runToolTimeoutCeilingMs` reads it, and only so a per-tool timeout + * stays under the budget it actually runs inside. Absent, the generic hosted + * ceiling is used — right for callers that have no chunk of their own. + */ + runSoftTimeoutMs?: number; toolLimits?: { timeoutMs?: number; maxResultChars?: number; @@ -4713,13 +4718,23 @@ export async function runAgentLoop(opts: { : 0; // A per-tool timeout above the chunk's own soft timeout can never fire — the // chunk boundary always wins — so the 12-minute default is dead code on a - // ~40s hosted foreground chunk. Background-function runs resolve to a ~13min - // ceiling and keep the default unchanged. + // ~40s hosted foreground chunk. + // + // TAKEN FROM THE CALLER'S ACTUAL BUDGET, not re-derived. Re-deriving it asked + // `resolveRunSoftTimeoutMs` for the generic background ceiling (13 min) even + // when the caller was a background AUTOMATION, whose real budget is its own + // hard abort minus headroom (10 min − 20s = 9m40s via + // `resolveBackgroundAutomationSoftTimeoutMs`). The ceiling came out ABOVE the + // run budget, so every per-tool timeout on that path was dead code and the + // chunk boundary won instead — which is the exact failure + // `RUN_TOOL_TIMEOUT_HEADROOM_MS` exists to prevent, reintroduced by guessing + // at a number the caller already knew. const runToolTimeoutCeilingMs = resolveRunToolTimeoutCeilingMs( - resolveRunSoftTimeoutMs(undefined, { - useHostedDefault: true, - backgroundFunction: isInBackgroundFunctionRuntime(), - }), + opts.runSoftTimeoutMs ?? + resolveRunSoftTimeoutMs(undefined, { + useHostedDefault: true, + backgroundFunction: isInBackgroundFunctionRuntime(), + }), ); const toolCallHistory: AgentLoopToolCallSummary[] = []; const sourceSweepToolCallHistory = seedSourceSweepToolCallsFromHistory( @@ -4984,14 +4999,7 @@ export async function runAgentLoop(opts: { lastProgressAt: number; bytes: number; }; - type ZeroByteToolInputRestart = { - toolName: string; - firstStartedAt: number; - lastStartedAt: number; - count: number; - }; const activeToolInputs = new Map(); - let zeroByteToolInputRestart: ZeroByteToolInputRestart | undefined; let endedForNoProgress = false; // Bracket the engine call for the run manager's no-progress backstop // (`inFlightWorkDelta` in run-manager.ts). That backstop measures the @@ -5049,64 +5057,60 @@ export async function runAgentLoop(opts: { ...(typeof progressBytes === "number" ? { progressBytes } : {}), }); }; - const actionPreparationDeadlineAt = () => { - let deadlineAt = Number.POSITIVE_INFINITY; - if (zeroByteToolInputRestart) { - deadlineAt = Math.min( - deadlineAt, - zeroByteToolInputRestart.firstStartedAt + - ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS, - ); - } - let earliestStartedAt = Number.POSITIVE_INFINITY; - let latestPositiveProgressAt = 0; - for (const active of activeToolInputs.values()) { - if (active.startedAt < earliestStartedAt) { - earliestStartedAt = active.startedAt; - } - if ( - active.bytes > 0 && - active.lastProgressAt > latestPositiveProgressAt - ) { - latestPositiveProgressAt = active.lastProgressAt; - } - } - const progressAt = - latestPositiveProgressAt > 0 - ? latestPositiveProgressAt - : earliestStartedAt; - if (Number.isFinite(progressAt)) { - deadlineAt = Math.min( - deadlineAt, - progressAt + ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS, - ); - } - return Number.isFinite(deadlineAt) ? deadlineAt : undefined; - }; - const modelStreamNoProgressDeadlineAt = () => { - const baseDeadlineAt = - lastModelStreamProgressAt + MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS; - // FIX 2: cap the FIRST event's deadline tighter on the clamped - // foreground runtime — see FOREGROUND_FIRST_MODEL_EVENT_TIMEOUT_MS - // for the ordering invariant this protects. + /** + * The ONLY in-loop stall bound left, and it covers exactly one thing: + * a model call whose stream opened and produced NOTHING AT ALL. + * + * WHAT WAS HERE, AND WHY IT IS GONE. Two 90s watchdogs used to run for + * the whole stream — one on silence between engine frames, one on a + * tool input whose byte count stopped growing — plus a zero-byte + * restart tripwire. Each inferred death from the ABSENCE of a + * particular event, and that inference is unsound on this transport: + * the Anthropic SDK drops the provider's `ping` keepalives before they + * reach any consumer (`core/streaming.js`: `if (sse.event === 'ping') + * continue;`, with no opt-out), so a healthy stream mid-generation is + * byte-for-byte indistinguishable from a wedged one. + * + * That is not an edge case, it is normal operation. A tool whose input + * is not eagerly streamed emits no `input_json_delta` at all while the + * provider composes its arguments, so writing a large file or filing a + * long structured result is a content-silent window whose length is set + * by the size of the argument. Production bore it out: of 27 one-shot + * analyst runs, 2 completed. Guards added for reliability were the + * thing taking it away. + * + * WHAT STILL CATCHES A REAL WEDGE — none of which can fire on + * slow-but-healthy work: + * • the engine's own first-event abort + * (`FIRST_STREAM_EVENT_TIMEOUT_MS`, 120s): a connection that opens + * and never speaks + * • the engine's total-stream deadline (`STREAM_TOTAL_TIMEOUT_MS`, + * 14min): one model call end to end, which is what bounds a socket + * that wedges MID-stream on the runtimes with no outer budget + * (local dev and self-hosted resolve the soft timeout to 0) + * • the run-manager backstop, for the segments OUTSIDE the stream + * (`inFlightWorkDelta` suspends it while the stream is open) + * • the per-tool timeout, which bounds tool EXECUTION at the tool + * • the chunk / run budget, which bounds COST rather than health + * • the stale reaper, which bounds worker liveness + * + * The cap below survives only because it guards the "nothing has + * happened yet" window on the clamped hosted FOREGROUND runtime, where + * the ~57s platform wall arrives before the engine's 120s bound could. + * The first real frame releases it, so long thinking, long tool inputs + * and long outputs are all past it by construction. + */ + const noProgressDeadlineAt = () => { if ( hasReceivedFirstEngineEvent || !isClampedForegroundRuntimeForThisCall ) { - return baseDeadlineAt; + return Number.POSITIVE_INFINITY; } - return Math.min( - baseDeadlineAt, - lastModelStreamProgressAt + FOREGROUND_FIRST_MODEL_EVENT_TIMEOUT_MS, + return ( + lastModelStreamProgressAt + FOREGROUND_FIRST_MODEL_EVENT_TIMEOUT_MS ); }; - const noProgressDeadlineAt = () => { - const actionDeadlineAt = actionPreparationDeadlineAt(); - const modelDeadlineAt = modelStreamNoProgressDeadlineAt(); - return actionDeadlineAt === undefined - ? modelDeadlineAt - : Math.min(actionDeadlineAt, modelDeadlineAt); - }; const hasNoProgressStalled = () => Date.now() >= noProgressDeadlineAt(); const checkpointNoProgress = () => { if (endedForNoProgress) return; @@ -5143,6 +5147,13 @@ export async function runAgentLoop(opts: { iterator: AsyncIterator, ): Promise> => { const deadlineAt = noProgressDeadlineAt(); + // No deadline at all is the COMMON case now — every runtime except a + // clamped hosted foreground call that has not yet seen its first + // frame. Await the iterator directly rather than racing it: a + // `setTimeout` of Infinity is coerced to 1ms by Node and would + // checkpoint instantly, turning "no bound" into "the tightest bound + // there is". + if (!Number.isFinite(deadlineAt)) return iterator.next(); const timeoutMs = Math.max(0, deadlineAt - Date.now()); if (timeoutMs <= 0) { checkpointNoProgress(); @@ -5183,36 +5194,6 @@ export async function runAgentLoop(opts: { bytes, }); }; - const resetZeroByteToolInputRestart = (toolName?: string) => { - if (!zeroByteToolInputRestart) return; - if (!toolName || zeroByteToolInputRestart.toolName === toolName) { - zeroByteToolInputRestart = undefined; - } - }; - const noteZeroByteToolInputStart = (toolName?: string) => { - if (!toolName) return false; - const now = Date.now(); - if (zeroByteToolInputRestart?.toolName === toolName) { - zeroByteToolInputRestart = { - ...zeroByteToolInputRestart, - lastStartedAt: now, - count: zeroByteToolInputRestart.count + 1, - }; - } else { - zeroByteToolInputRestart = { - toolName, - firstStartedAt: now, - lastStartedAt: now, - count: 1, - }; - } - return ( - zeroByteToolInputRestart.count >= - ACTION_PREPARATION_ZERO_BYTE_RESTART_LIMIT && - now - zeroByteToolInputRestart.firstStartedAt >= - ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS - ); - }; const eventIterator = eventStream[Symbol.asyncIterator](); let eventIteratorDone = false; openModelStreamBracket(); @@ -5254,7 +5235,6 @@ export async function runAgentLoop(opts: { } } if (event.type === "text-delta") { - resetZeroByteToolInputRestart(); streamedAssistantText += event.text; send({ type: "text", text: event.text }); } else if (event.type === "thinking-delta") { @@ -5276,17 +5256,12 @@ export async function runAgentLoop(opts: { ...(event.id ? { id: event.id } : {}), }); sendToolInputActivity(event.name, key, undefined, true); - if (noteZeroByteToolInputStart(event.name)) { - checkpointNoProgress(); - break; - } } else if (event.type === "tool-input-delta") { const key = event.id ?? event.name; const toolName = event.name ?? (event.id ? toolInputNames.get(event.id) : undefined); let progressBytes: number | undefined; - let startedZeroByteInput = false; if (key) { const hadByteRecord = toolInputBytes.has(key); const previous = hadByteRecord @@ -5298,11 +5273,6 @@ export async function runAgentLoop(opts: { toolInputBytes.set(key, progressBytes); if (!hadByteRecord || progressBytes > previous) { trackActiveToolInput(key, toolName, progressBytes); - if (progressBytes > 0) { - resetZeroByteToolInputRestart(); - } else if (!hadByteRecord) { - startedZeroByteInput = true; - } } } if (event.text) { @@ -5314,14 +5284,6 @@ export async function runAgentLoop(opts: { }); } sendToolInputActivity(toolName, key, progressBytes); - if ( - startedZeroByteInput && - toolName && - noteZeroByteToolInputStart(toolName) - ) { - checkpointNoProgress(); - break; - } } else if (event.type === "gateway-heartbeat") { send({ type: "stream_keepalive" }); } else if (event.type === "tool-call") { @@ -10236,6 +10198,24 @@ export function createProductionAgentHandler( ) : null; + // The budget this run ACTUALLY executes inside, resolved once and used by + // both `startRun` (which arms the chunk timer with it) and the agent loop + // (which clamps per-tool timeouts under it). Resolving it only inside + // `startRun` left the loop to re-derive a generic hosted/background + // ceiling, so an app-configured chunk shorter than that ceiling got + // per-tool timeouts longer than the chunk containing them — dead code, and + // the chunk boundary won instead. `resolveRunSoftTimeoutMs` clamps an + // already-resolved number to itself, so passing it back in is a no-op. + const resolvedRunSoftTimeoutMs = resolveRunSoftTimeoutMs( + selfChainBudget && !selfChainBudget.skipToBoundary + ? selfChainBudget.softTimeoutMs + : options.runSoftTimeoutMs, + { + useHostedDefault: true, + backgroundFunction: runsInBackgroundFunction, + }, + ); + const startedRun = startRun( runId, effectiveThreadId, @@ -10356,6 +10336,15 @@ export function createProductionAgentHandler( providerOptions: options.providerOptions, executionMode: requestMode, maxIterations: loopSettings.maxIterations, + // Same `startRun` chunk and same signal as the main loop, so + // the same budget. Left off, the loop re-derives the generic + // hosted/background ceiling, which can sit above the chunk + // these nested calls actually run inside — and then the + // per-tool timeout is unreachable and the chunk boundary + // preempts it. + ...(resolvedRunSoftTimeoutMs > 0 + ? { runSoftTimeoutMs: resolvedRunSoftTimeoutMs } + : {}), }); // Attribute custom-agent sub-calls under their own label @@ -10537,6 +10526,13 @@ export function createProductionAgentHandler( priorTurnInputTokens: turnInputTokens, finalResponseGuard: options.finalResponseGuard, finalResponseGuardRequestText: messageToPersist, + // The chunk this loop is running inside, so a per-tool timeout is + // clamped under the budget it can actually spend rather than under a + // re-derived generic ceiling. `0` (local dev) keeps the loop's own + // fallback. + ...(resolvedRunSoftTimeoutMs > 0 + ? { runSoftTimeoutMs: resolvedRunSoftTimeoutMs } + : {}), ...(options.toolLimits ? { toolLimits: options.toolLimits } : {}), ...(threadId ? { threadId: effectiveThreadId, turnId: effectiveTurnId } @@ -10706,10 +10702,7 @@ export function createProductionAgentHandler( // (durable-background worker, plain foreground POST) is unaffected: // `selfChainBudget` is `null` for them and this falls through to the // exact prior value. - softTimeoutMs: - selfChainBudget && !selfChainBudget.skipToBoundary - ? selfChainBudget.softTimeoutMs - : options.runSoftTimeoutMs, + softTimeoutMs: resolvedRunSoftTimeoutMs, useHostedSoftTimeoutDefault: true, // Lift the soft-timeout clamp to ~13min ONLY when this run is actually // executing inside a real Netlify `-background` function (15-min budget, diff --git a/packages/core/src/agent/run-loop-with-resume.spec.ts b/packages/core/src/agent/run-loop-with-resume.spec.ts index 3de6b9377a..6ced7e9b59 100644 --- a/packages/core/src/agent/run-loop-with-resume.spec.ts +++ b/packages/core/src/agent/run-loop-with-resume.spec.ts @@ -606,6 +606,52 @@ describe("runAgentLoopDirectWithSoftTimeout", () => { } }); + // `stableOpts` carries the FULL invocation budget, but round 2+ runs inside + // `roundTimeoutMs` — what is left after the earlier rounds spent wall-clock. + // Handing the loop the full window let it clamp a per-tool timeout above the + // round containing it, so the round timer won and the per-tool timeout was + // unreachable: the inversion `RUN_TOOL_TIMEOUT_HEADROOM_MS` exists to + // prevent, one scope down. + it("gives each resumed round the budget actually left, not the invocation's", async () => { + vi.useFakeTimers(); + try { + const seenBudgets: (number | undefined)[] = []; + let attempts = 0; + mockRunAgentLoop.mockImplementation(async (opts) => { + attempts++; + seenBudgets.push(opts.runSoftTimeoutMs); + if (attempts === 1) { + // Round 1 spends two minutes of the invocation, then checkpoints. + vi.setSystemTime(Date.now() + 120_000); + opts.send({ type: "auto_continue", reason: "stream_ended" }); + } else { + opts.send({ type: "text", text: "finished" }); + } + return { + inputTokens: 1, + outputTokens: 1, + cacheReadTokens: 0, + cacheWriteTokens: 0, + model: "test-model", + }; + }); + + await runAgentLoopDirectWithSoftTimeout( + makeOpts( + [{ role: "user", content: [{ type: "text", text: "go" }] }], + new AbortController().signal, + ), + 600_000, + { backgroundFunction: true }, + ); + + expect(attempts).toBe(2); + expect(seenBudgets[0]).toBe(600_000); + expect(seenBudgets[1]).toBe(480_000); + } finally { + vi.useRealTimers(); + } + }); it("lets a proven background delegated run finish after the foreground continuation cap", async () => { const sentEvents: AgentChatEvent[] = []; const outcomes: AgentLoopOutcome[] = []; diff --git a/packages/core/src/agent/run-loop-with-resume.ts b/packages/core/src/agent/run-loop-with-resume.ts index 34c908680e..c2ec94b558 100644 --- a/packages/core/src/agent/run-loop-with-resume.ts +++ b/packages/core/src/agent/run-loop-with-resume.ts @@ -333,8 +333,19 @@ export async function runAgentLoopDirectWithSoftTimeout( const finalResponseGuardRequestText = opts.finalResponseGuardRequestText ?? resolveFinalResponseGuardRequestText(opts.messages); - const stableOpts = { ...opts, finalResponseGuardRequestText }; const timeoutMs = resolveRunSoftTimeoutMs(softTimeoutMs, timeoutOptions); + // Hand the loop the budget it is ACTUALLY running inside, so a per-tool + // timeout is clamped under this chunk rather than under a re-derived generic + // ceiling. A background automation's budget is its own hard abort minus + // headroom and is materially smaller than the background chat ceiling; the + // loop had no way to know that and guessed high, which made every per-tool + // timeout on that path unreachable. `0` means "no soft-timeout regime" + // (local dev), where the loop's own fallback is the right answer. + const stableOpts = { + ...opts, + finalResponseGuardRequestText, + ...(timeoutMs > 0 ? { runSoftTimeoutMs: timeoutMs } : {}), + }; let finalOutcomeReported = false; const reportFinalOutcome = (outcome: AgentLoopOutcome) => { if (finalOutcomeReported) return; @@ -564,6 +575,14 @@ export async function runAgentLoopDirectWithSoftTimeout( let attemptOutcome: AgentLoopOutcome | undefined; const nextUsage = await runAgentLoop({ ...stableOpts, + // THIS round's budget, not the invocation's. `stableOpts` carries the + // full `timeoutMs`, but round 2+ runs inside `roundTimeoutMs` — what + // is left after the earlier rounds spent wall-clock. Clamping a + // per-tool timeout against the full window puts it above the round + // that contains it, so the round timer wins and the per-tool timeout + // is unreachable — the same inversion `RUN_TOOL_TIMEOUT_HEADROOM_MS` + // exists to prevent, one scope down. + runSoftTimeoutMs: roundTimeoutMs, send, signal: controller.signal, onOutcome: (outcome) => { diff --git a/packages/core/src/agent/run-manager.spec.ts b/packages/core/src/agent/run-manager.spec.ts index 9545c69298..2165af1d9d 100644 --- a/packages/core/src/agent/run-manager.spec.ts +++ b/packages/core/src/agent/run-manager.spec.ts @@ -2,6 +2,7 @@ import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; import { BACKGROUND_SOFT_TIMEOUT_CEILING_MS, + BACKGROUND_AUTOMATION_SOFT_TIMEOUT_HEADROOM_MS, RUN_NO_PROGRESS_HARD_TIMEOUT_MS, } from "../app-config/run-lifecycle-invariants.js"; import { @@ -3817,6 +3818,32 @@ describe("run manager soft timeout", () => { expect(toolCeiling).toBe(35_000); }); + // The same inversion, on the path that actually runs the one-shot + // automations: a background AUTOMATION's budget is its own hard abort minus + // headroom (10min - 20s), which is materially SMALLER than the background + // chat ceiling (13min). `runAgentLoop` used to re-derive the ceiling from + // the chat number and got 12m55s — above the 9m40s the run actually had — + // so every per-tool timeout on that path was dead code and the chunk + // boundary won instead. It now takes the caller's real budget. + it("keeps the tool ceiling inside a background AUTOMATION's own budget", () => { + // `agent.backgroundRunHardTimeoutMs` default (background-automation-runner.ts). + // Inlined rather than imported so this spec does not pull the jobs module. + const automationHardAbortMs = 10 * 60_000; + const automationBudgetMs = + automationHardAbortMs - BACKGROUND_AUTOMATION_SOFT_TIMEOUT_HEADROOM_MS; + + // The bug: derived from the chat ceiling, the tool ceiling outlives the + // budget it is supposed to sit inside. + expect( + resolveRunToolTimeoutCeilingMs(BACKGROUND_SOFT_TIMEOUT_CEILING_MS), + ).toBeGreaterThan(automationBudgetMs); + + // The fix: derived from the caller's actual budget, it stays under it. + expect(resolveRunToolTimeoutCeilingMs(automationBudgetMs)).toBeLessThan( + automationBudgetMs, + ); + }); + it("clamps a background-sized foreground override down to the chunk budget", () => { // templates/analytics passes 3min unconditionally — a background-sized // value that outlives both the serverless wall and the client watchdog. diff --git a/packages/core/src/agent/run-manager.ts b/packages/core/src/agent/run-manager.ts index 2ae9365291..91ca242e6e 100644 --- a/packages/core/src/agent/run-manager.ts +++ b/packages/core/src/agent/run-manager.ts @@ -240,10 +240,11 @@ export function resolveRunNoProgressTimeoutMs(params: { * Every pair listed here suspends the no-progress backstop for as long as it is * open, so each one MUST be bounded by a watchdog of its own — tool calls by * the per-tool timeout, cross-app calls by the A2A poll timeout, the model - * stream by `MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS`, which the agent loop races - * against every wait for the next engine frame. A pair added here without such - * a bound turns the backstop off for the rest of the run, which is strictly - * worse than the stall it was meant to catch. + * stream by the engine's own first-event abort plus the chunk budget (the 90s + * in-loop watchdog that used to sit here is gone — see + * run-lifecycle-invariants.ts). A pair added here without SOME bound turns the + * backstop off for the rest of the run, which is strictly worse than the stall + * it was meant to catch. * * Note what that leaves: the model-stream bound covers waiting for the engine, * not a hang while the loop processes a frame it already has. Nothing here diff --git a/packages/core/src/agent/run-store.spec.ts b/packages/core/src/agent/run-store.spec.ts index 079443e023..304896c3b6 100644 --- a/packages/core/src/agent/run-store.spec.ts +++ b/packages/core/src/agent/run-store.spec.ts @@ -237,6 +237,11 @@ const { CHECKPOINT_TERMINAL_EVENT_SEQ, getCurrentTurnEventsForThread, __resetNoRunningRunsProbeForTests, + describeStaleReap, + staleWindowMsForRow, + BACKGROUND_PROCESSING_RUN_STALE_MS, + BACKGROUND_RUN_STALE_MS, + RUN_STALE_MS, } = await import("./run-store.js"); // Mock storage for ledger SELECT responses, keyed by toolKey @@ -1631,3 +1636,122 @@ describe("terminal status is `completed` iff the terminal reason is `done`", () } }); }); + +describe("stale-reap forensics", () => { + const BASE = 1_000_000; + + it("picks the same window the reap SQL does, for all three cases", () => { + // Mirrors `backgroundAwareStaleCutoffSql`. A background row WITH a + // dispatch payload has a successor to reach, so it gets the tight + // post-claim window; one without has nothing to recover and gets the + // wider background window; foreground keeps the tight default. + expect( + staleWindowMsForRow({ + dispatchMode: "background-processing", + hasDispatchPayload: true, + }), + ).toBe(BACKGROUND_PROCESSING_RUN_STALE_MS); + expect( + staleWindowMsForRow({ + dispatchMode: "background-processing", + hasDispatchPayload: false, + }), + ).toBe(BACKGROUND_RUN_STALE_MS); + expect(staleWindowMsForRow({ dispatchMode: "background" })).toBe( + BACKGROUND_RUN_STALE_MS, + ); + expect(staleWindowMsForRow({ dispatchMode: "foreground" })).toBe( + RUN_STALE_MS, + ); + expect(staleWindowMsForRow({})).toBe(RUN_STALE_MS); + }); + + it("an explicit maxStaleMs overrides the dispatch-mode window", () => { + expect( + staleWindowMsForRow({ dispatchMode: "background", maxStaleMs: 1234 }), + ).toBe(1234); + }); + + it("separates a dead worker from a live worker that stopped producing", () => { + // Dead worker: heartbeat and progress stop together. + const dead = describeStaleReap({ + startedAt: BASE, + heartbeatAt: BASE + 300_000, + lastProgressAt: BASE + 300_000, + inFlightSince: null, + dispatchMode: "background-processing", + hasDispatchPayload: false, + now: BASE + 400_000, + }); + expect(dead).toContain("hbAheadOfProgress=0"); + + // Live worker, wedged loop: the heartbeat runs on for the better part of an + // hour past the last real progress. This is the shape one production run + // showed and that nothing recorded. + const wedged = describeStaleReap({ + startedAt: BASE, + heartbeatAt: BASE + 3_309_000, + lastProgressAt: BASE + 293_000, + inFlightSince: null, + dispatchMode: "background-processing", + hasDispatchPayload: false, + now: BASE + 3_400_000, + }); + expect(wedged).toContain("hbAheadOfProgress=3016000"); + }); + + it("reports the window actually applied and whether a successor was possible", () => { + const detail = describeStaleReap({ + startedAt: BASE, + heartbeatAt: BASE + 10_000, + lastProgressAt: BASE + 5_000, + inFlightSince: BASE + 8_000, + dispatchMode: "background-processing", + hasDispatchPayload: false, + now: BASE + 120_000, + }); + expect(detail).toContain(`window=${BACKGROUND_RUN_STALE_MS}`); + expect(detail).toContain("dispatch=background-processing"); + expect(detail).toContain("redispatchable=0"); + expect(detail).toContain("sinceHeartbeat=110000"); + expect(detail).toContain("sinceProgress=115000"); + expect(detail).toContain("inFlight=1"); + expect(detail).toContain("inFlightFor=112000"); + // `runAge` is measured to the liveness basis, not to the reap — the reap + // time is detection latency, not run duration. + expect(detail).toContain("runAge=10000"); + }); + + it("carries no user content — only numbers, booleans and an enum", () => { + const detail = describeStaleReap({ + startedAt: BASE, + heartbeatAt: BASE + 1, + lastProgressAt: BASE + 1, + inFlightSince: null, + dispatchMode: "background", + hasDispatchPayload: true, + now: BASE + 2, + }); + // Every token is `key=`; nothing free-form can reach it. + for (const part of detail.split(" ")) { + expect(part).toMatch( + /^[a-zA-Z]+=(-?\d+|none|background[a-z-]*|foreground)$/, + ); + } + }); + + it("omits fields it has no value for rather than reporting zero", () => { + const detail = describeStaleReap({ + startedAt: null, + heartbeatAt: null, + lastProgressAt: null, + inFlightSince: null, + dispatchMode: null, + now: BASE, + }); + expect(detail).not.toContain("sinceHeartbeat"); + expect(detail).not.toContain("hbAheadOfProgress"); + expect(detail).toContain("inFlight=0"); + expect(detail).toContain("dispatch=none"); + }); +}); diff --git a/packages/core/src/agent/run-store.ts b/packages/core/src/agent/run-store.ts index da0eecb339..de2efcf712 100644 --- a/packages/core/src/agent/run-store.ts +++ b/packages/core/src/agent/run-store.ts @@ -784,6 +784,81 @@ function backgroundAwareStaleCutoffSql(): string { return `(CAST(? AS BIGINT) - CASE WHEN dispatch_mode = 'background-processing' AND dispatch_payload IS NOT NULL THEN ${BACKGROUND_PROCESSING_RUN_STALE_MS} WHEN dispatch_mode LIKE 'background%' THEN ${BACKGROUND_RUN_STALE_MS} ELSE ${RUN_STALE_MS} END)`; } +/** + * Which stale window the reaper applied to a row, in ms. + * + * MIRRORS `backgroundAwareStaleCutoffSql`, which decides the same thing in SQL + * because it has to run inside the conditional UPDATE. Kept beside it and + * covered by a test asserting the three cases agree — a drift here reports the + * wrong window on a real incident, which is worse than reporting none. + */ +export function staleWindowMsForRow(row: { + dispatchMode?: string | null; + hasDispatchPayload?: boolean; + maxStaleMs?: number; +}): number { + if (typeof row.maxStaleMs === "number") return row.maxStaleMs; + const mode = row.dispatchMode ?? ""; + if (mode === "background-processing" && row.hasDispatchPayload) + return BACKGROUND_PROCESSING_RUN_STALE_MS; + if (mode.startsWith("background")) return BACKGROUND_RUN_STALE_MS; + return RUN_STALE_MS; +} + +/** + * The liveness forensics for one reap, as a compact `key=value` line. + * + * THE FIELD THAT MATTERS IS `hbAheadOfProgress`. A worker that died takes its + * heartbeat with it, so heartbeat and last-progress stop together and this is + * ~0. A worker still running while the agent loop stops producing keeps + * heartbeating, and this grows without bound — those are opposite bugs that + * look identical in `agent_runs` today. Production showed runs where the + * heartbeat ran 3,000s past the last progress; nothing recorded that, so + * nothing could act on it. + * + * Numbers, booleans and an enum only — no prompt, no result, no user content — + * so this obeys the same privacy rule as event properties and log lines. + */ +export function describeStaleReap(row: { + startedAt?: number | null; + heartbeatAt?: number | null; + lastProgressAt?: number | null; + inFlightSince?: number | null; + dispatchMode?: string | null; + hasDispatchPayload?: boolean; + maxStaleMs?: number; + now: number; +}): string { + const { now } = row; + const started = row.startedAt ?? null; + const heartbeat = row.heartbeatAt ?? null; + const progress = row.lastProgressAt ?? null; + const liveness = Math.max( + progress ?? started ?? 0, + heartbeat ?? started ?? 0, + ); + const parts: string[] = [ + `window=${staleWindowMsForRow(row)}`, + `dispatch=${row.dispatchMode ?? "none"}`, + `redispatchable=${row.hasDispatchPayload ? "1" : "0"}`, + ]; + if (heartbeat != null) parts.push(`sinceHeartbeat=${now - heartbeat}`); + if (progress != null) parts.push(`sinceProgress=${now - progress}`); + // The discriminator. Negative would mean progress outlived the heartbeat, + // which is possible and equally worth seeing. + if (heartbeat != null && progress != null) + parts.push(`hbAheadOfProgress=${heartbeat - progress}`); + // Only when it is a real duration. A liveness basis before `started_at` means + // clock skew or a mocked row, and printing a negative age reads as a fact + // about the run rather than a fact about the clock. + if (started != null && liveness >= started) + parts.push(`runAge=${liveness - started}`); + parts.push(`inFlight=${row.inFlightSince != null ? "1" : "0"}`); + if (row.inFlightSince != null) + parts.push(`inFlightFor=${now - row.inFlightSince}`); + return parts.join(" "); +} + function terminalRunEventExclusionSql(runIdColumn = "id"): string { return `NOT EXISTS ( SELECT 1 FROM agent_run_events terminal_events @@ -1457,6 +1532,24 @@ export const RUN_DIAG_STAGE = { * no boundary previously recorded anywhere. */ runBoundaryReached: "run_boundary_reached", + /** + * A stale reaper flipped this run to `errored`. Detail carries the liveness + * forensics — see `describeStaleReap`. + * + * WHY THIS EXISTS. `stale_run` is the single largest terminal outcome on the + * one-shot automation path (14 of 27 runs in one production deployment) and + * the row records nothing about WHY: `error_detail` is a fixed sentence for + * every reap, so a correct reap and a false one are indistinguishable after + * the fact. Every question worth asking needed a number nobody stored — was + * the worker dead, or was it heartbeating happily while the loop stopped + * producing? which of the three stale windows fired? was the in-flight grace + * in play? One production run heartbeated 3,309s past a 600s hard abort and + * there is no way to tell from the row what kept it alive. + * + * Diagnostics only: nothing reads this to make a decision, and it cannot + * change whether a row is reaped. + */ + staleRunReaped: "stale_run_reaped", } as const; export type RunDiagStage = (typeof RUN_DIAG_STAGE)[keyof typeof RUN_DIAG_STAGE]; @@ -1964,6 +2057,50 @@ async function reapSingleStaleRun( reaped = (rowsAffected ?? 0) > 0; } + // FORENSICS, on the reap path only. A speculative `reapIfStale` that reaps + // nothing does no extra work; an actual reap is rare enough to afford one + // read. + // + // ONE diagnostic write, not two. `diag_stage` holds a single value, so an + // independent forensics write would overwrite the recovery outcome that + // already lands here — trading the answer to "did a successor get created" + // for the answer to "why did it die". Both fit in one line, so both are + // recorded: the recovery outcome keeps its own stage name and leading + // position, and the liveness numbers are appended. + let forensics = ""; + if (reaped) { + forensics = await client + .execute({ + sql: `SELECT started_at, heartbeat_at, last_progress_at, in_flight_since, + dispatch_mode, dispatch_payload + FROM agent_runs WHERE id = ?`, + args: [runId], + }) + .then((res) => { + const row = (res.rows as unknown as Array>)[0]; + if (!row) return "forensics=row_missing"; + const num = (v: unknown) => (v == null ? null : Number(v)); + return describeStaleReap({ + startedAt: num(row.started_at), + heartbeatAt: num(row.heartbeat_at), + lastProgressAt: num(row.last_progress_at), + inFlightSince: num(row.in_flight_since), + dispatchMode: (row.dispatch_mode as string | null) ?? null, + hasDispatchPayload: row.dispatch_payload != null, + ...(typeof maxStaleMs === "number" ? { maxStaleMs } : {}), + now: completedAt, + }); + }) + // Best-effort throughout: a diagnostic that could fail a reap would be + // strictly worse than no diagnostic. But an empty string reads as "reaped + // with nothing worth saying" — the exact ambiguity these forensics exist + // to remove — so an unreadable row says so instead of going quiet. + .catch( + (err) => + `forensics=unreadable ${(err instanceof Error ? err.message : String(err)).slice(0, 120)}`, + ); + } + if (reaped && outcome && outcome.outcome !== "not_background") { const detail = outcome.outcome === "recovered" @@ -1972,12 +2109,19 @@ async function reapSingleStaleRun( await recordRunDiagnostic( runId, RUN_DIAG_STAGE.staleRunRecoveryAttempted, - detail, + forensics ? `${detail} ${forensics}` : detail, ).catch(() => {}); if (outcome.outcome === "recovered") { attemptStaleRunRecoveryDispatch(outcome.successorRunId); } + } else if (reaped && forensics) { + await recordRunDiagnostic( + runId, + RUN_DIAG_STAGE.staleRunReaped, + forensics, + ).catch(() => {}); } + return reaped; } diff --git a/packages/core/src/agent/types.ts b/packages/core/src/agent/types.ts index bc63c64c37..6d011396fd 100644 --- a/packages/core/src/agent/types.ts +++ b/packages/core/src/agent/types.ts @@ -306,12 +306,17 @@ export type AgentChatEvent = * without producing any forwarded event, so the backstop's clock saw pure * silence and killed demonstrably-alive runs at 150s. `trackInFlightWork` * counts this pair exactly like `tool_start`/`tool_done`: an engine call - * in flight suspends the backstop, bounded by the in-loop watchdog the - * same way a tool call is bounded by its own timeout. + * in flight suspends the backstop. + * + * WHAT BOUNDS THE SUSPENDED WINDOW, now that the in-loop watchdogs are + * gone: the engine's own first-event abort covers a call that never + * speaks, and the chunk/run budget covers everything after that. An + * in-stream wedge AFTER the first frame is therefore caught by the budget + * rather than by a dedicated clock — a deliberate trade, because no clock + * here could tell it apart from a model composing a large tool argument. * * Deliberately NOT a keepalive: a keepalive proves the transport is up, - * this proves the loop is inside a model call it will be held accountable - * for by `MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS`. + * this proves the loop is inside a model call. */ type: "model_stream"; status: "start" | "end"; diff --git a/packages/core/src/app-config/run-lifecycle-invariants.ts b/packages/core/src/app-config/run-lifecycle-invariants.ts index f954211624..8729d45c8e 100644 --- a/packages/core/src/app-config/run-lifecycle-invariants.ts +++ b/packages/core/src/app-config/run-lifecycle-invariants.ts @@ -117,17 +117,25 @@ export const BACKGROUND_SOFT_TIMEOUT_CEILING_MS = 13 * 60_000; export const RUN_NO_PROGRESS_HARD_TIMEOUT_MS = 150_000; /** - * Default in-loop watchdog for silence while an action's arguments stream in. - * Read through `resolveActionPreparationNoProgressTimeoutMs`, never directly: - * a host diagnosing a timeout has to be able to see and change this number. - */ -export const ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS = 90_000; - -/** - * Default in-loop watchdog for silence between engine stream frames. Read - * through `resolveModelStreamNoProgressTimeoutMs`, never directly. + * THE IN-LOOP NO-PROGRESS WATCHDOGS ARE GONE, and their absence is the design. + * + * Two 90s bounds used to live here — one on silence between engine frames, + * one on a tool input whose byte count stopped growing. Both inferred a dead + * stream from the absence of a particular event, and on the Anthropic + * transport that inference cannot be made: the SDK drops the provider's `ping` + * keepalives before any consumer sees them (`core/streaming.js`), so a model + * composing a large tool argument is indistinguishable from a wedged socket. + * Only a tool declared for eager input streaming emits anything at all while + * its arguments are generated, so the silent case is ORDINARY, not + * exceptional. + * + * They were added to make runs more reliable and did the opposite: of 27 + * one-shot analyst runs in production, 2 completed. Deleting them leaves the + * bounds that key off evidence rather than absence — the engine's own + * first-event abort, the run-manager backstop outside the stream, the per-tool + * execution timeout, the chunk budget, and the stale reaper. Reintroducing a + * clock here needs a liveness signal this process can actually observe. */ -export const MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS = 90_000; /** * Consecutive chunks allowed to end on the SAME terminal error code having @@ -276,9 +284,6 @@ export function assertRunLifecycleInvariants(agent: AppConfig["agent"]): void { // the relationship below extended to cover it. const { backgroundNoProgressTimeoutMs, backgroundRunHardTimeoutMs } = agent; const backgroundSoftTimeoutCeilingMs = BACKGROUND_SOFT_TIMEOUT_CEILING_MS; - const modelStreamNoProgressTimeoutMs = MODEL_STREAM_NO_PROGRESS_TIMEOUT_MS; - const actionPreparationNoProgressTimeoutMs = - ACTION_PREPARATION_NO_PROGRESS_TIMEOUT_MS; const maxBackgroundRunContinuations = MAX_BACKGROUND_RUN_CONTINUATIONS; const maxConsecutiveNoProgressContinuations = MAX_CONSECUTIVE_NO_PROGRESS_CONTINUATIONS; @@ -306,20 +311,6 @@ export function assertRunLifecycleInvariants(agent: AppConfig["agent"]): void { // A disabled backstop (0) has no ordering to satisfy — it never fires. if (backgroundNoProgressTimeoutMs > 0) { - require("in-loop watchdog before the run-manager backstop", { - key: "agent.modelStreamNoProgressTimeoutMs", - value: modelStreamNoProgressTimeoutMs, - }, { - key: "agent.backgroundNoProgressTimeoutMs", - value: backgroundNoProgressTimeoutMs, - }, "the in-loop watchdog emits a boundary the agent loop itself recovers; the run-manager backstop is the coarser one above it"); - require("action-preparation watchdog before the run-manager backstop", { - key: "agent.actionPreparationNoProgressTimeoutMs", - value: actionPreparationNoProgressTimeoutMs, - }, { - key: "agent.backgroundNoProgressTimeoutMs", - value: backgroundNoProgressTimeoutMs, - }, "a stalled argument stream must be caught by the watchdog that knows which tool stalled"); require("background backstop inside the background chunk budget", { key: "agent.backgroundNoProgressTimeoutMs", value: backgroundNoProgressTimeoutMs, diff --git a/templates/factory/changelog/2026-08-21-activity-runs-use-automation-display-names.md b/templates/factory/changelog/2026-08-21-activity-runs-use-automation-display-names.md index d5d9864016..ad2cd6bd2e 100644 --- a/templates/factory/changelog/2026-08-21-activity-runs-use-automation-display-names.md +++ b/templates/factory/changelog/2026-08-21-activity-runs-use-automation-display-names.md @@ -2,4 +2,5 @@ type: improved date: 2026-08-21 --- + Activity run history labels each run with the automation's display name instead of its full resource path. diff --git a/templates/factory/changelog/2026-08-21-create-and-settings-source-cards.md b/templates/factory/changelog/2026-08-21-create-and-settings-source-cards.md index 4ec97df68f..bce8c299a1 100644 --- a/templates/factory/changelog/2026-08-21-create-and-settings-source-cards.md +++ b/templates/factory/changelog/2026-08-21-create-and-settings-source-cards.md @@ -2,4 +2,5 @@ type: improved date: 2026-08-21 --- + Create Factory and Settings now share the same labeled source cards, Enable polling toggles, and uncrowded scheduler health rows. diff --git a/templates/factory/changelog/2026-08-21-keep-automations-visible-while-running.md b/templates/factory/changelog/2026-08-21-keep-automations-visible-while-running.md index f23e22a8e5..679c4c54e1 100644 --- a/templates/factory/changelog/2026-08-21-keep-automations-visible-while-running.md +++ b/templates/factory/changelog/2026-08-21-keep-automations-visible-while-running.md @@ -2,4 +2,5 @@ type: fixed date: 2026-08-21 --- + Automations remain visible while running, with live status updates in Automations and Activity. diff --git a/templates/factory/changelog/2026-08-21-nested-factory-automations-can-poll.md b/templates/factory/changelog/2026-08-21-nested-factory-automations-can-poll.md index 447f09f2cb..c3ed6f5d32 100644 --- a/templates/factory/changelog/2026-08-21-nested-factory-automations-can-poll.md +++ b/templates/factory/changelog/2026-08-21-nested-factory-automations-can-poll.md @@ -2,4 +2,5 @@ type: fixed date: 2026-08-21 --- + Factory Slack, GitHub, and Sentry automations now run for nested factories instead of failing before they can poll. diff --git a/templates/factory/changelog/2026-08-21-settings-sticky-unsaved-bar.md b/templates/factory/changelog/2026-08-21-settings-sticky-unsaved-bar.md index ce69447b7e..442910473b 100644 --- a/templates/factory/changelog/2026-08-21-settings-sticky-unsaved-bar.md +++ b/templates/factory/changelog/2026-08-21-settings-sticky-unsaved-bar.md @@ -2,4 +2,5 @@ type: improved date: 2026-08-21 --- + Factory settings now show a sticky Save and Discard bar at the top as soon as a field changes, instead of a save button buried below the page.