3199bd3d90
Addresses two issues identified by cubic on PR #3952. 1. Watchdog cancellation was too narrow — only `text`/`reasoning` parts counted as progress, so a subagent that immediately ran tools (Read/Bash/Edit) emitted `tool`/`tool_use`/`tool_result`/`tool-call`/ `step-start` parts that the watchdog ignored, risking a false fire on actively-working subagents. Broaden to: any assistant part of any known type counts as progress (the model has started responding, whether or not visible text has arrived yet). `info.error` and `info.finish` continue to cancel. 2. Test timing margins were tight (15ms pre-cancel against a 40ms timer), risking CI flakiness on loaded runners. Bumped to a 100ms threshold with a 40ms pre-cancel window and a 250ms post-fire wait, giving a 60ms margin before the timer fires and ~2.5x the threshold after — robust against scheduler delay. Refactor for testability: extracted the OpenCode-event→watchdog-signal translation out of `hook.ts` into an exported `observeEventForWatchdog` helper on the watchdog module. This let me add direct unit tests for every part-type case (text, reasoning, tool, tool_use, tool_result, tool-call, step-start, file) plus the error/finish/empty-parts branches without spinning up the full hook. Net diff: hook.ts shrinks, watchdog module gains a small pure function with parametrised coverage. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
340 lines
12 KiB
TypeScript
340 lines
12 KiB
TypeScript
import { afterEach, beforeEach, describe, expect, it } from "bun:test"
|
|
import type { HookDeps, RuntimeFallbackPluginInput } from "./types"
|
|
import type { AutoRetryHelpers } from "./auto-retry"
|
|
import { subagentSessions } from "../../features/claude-code-session-state"
|
|
import { createFirstPromptWatchdog, observeEventForWatchdog, type FirstPromptWatchdog } from "./first-prompt-watchdog"
|
|
|
|
// Real timers are unavoidable here (bun:test has no built-in fake-timer API),
|
|
// so margins are sized generously to survive a loaded CI runner. Specifically:
|
|
// - SAFE_WAIT_BEFORE_FIRE_MS must be << WATCHDOG_MS so the cancel call lands
|
|
// before the timer fires even with significant scheduler delay
|
|
// (margin: WATCHDOG_MS - SAFE_WAIT_BEFORE_FIRE_MS >= 60ms here).
|
|
// - SAFE_WAIT_AFTER_FIRE_MS must be >> WATCHDOG_MS so we conclusively
|
|
// observe whether the timer fired (margin: ~2.5x WATCHDOG_MS).
|
|
const WATCHDOG_MS = 100
|
|
const SAFE_WAIT_BEFORE_FIRE_MS = 40
|
|
const SAFE_WAIT_AFTER_FIRE_MS = 250
|
|
|
|
function wait(ms: number): Promise<void> {
|
|
return new Promise((resolve) => setTimeout(resolve, ms))
|
|
}
|
|
|
|
function createContext(): RuntimeFallbackPluginInput {
|
|
return {
|
|
client: {
|
|
session: {
|
|
abort: async () => ({}),
|
|
messages: async () => ({ data: [] }),
|
|
promptAsync: async () => ({}),
|
|
},
|
|
tui: {
|
|
showToast: async () => ({}),
|
|
},
|
|
},
|
|
directory: "/test/dir",
|
|
}
|
|
}
|
|
|
|
function createDeps(pluginConfig: Record<string, unknown> = {}): HookDeps {
|
|
return {
|
|
ctx: createContext(),
|
|
config: {
|
|
enabled: true,
|
|
retry_on_errors: [429, 503, 529],
|
|
max_fallback_attempts: 3,
|
|
cooldown_seconds: 60,
|
|
timeout_seconds: 30,
|
|
notify_on_fallback: false,
|
|
},
|
|
options: undefined,
|
|
pluginConfig,
|
|
sessionStates: new Map(),
|
|
sessionLastAccess: new Map(),
|
|
sessionRetryInFlight: new Set(),
|
|
sessionAwaitingFallbackResult: new Set(),
|
|
sessionFallbackTimeouts: new Map(),
|
|
sessionStatusRetryKeys: new Map(),
|
|
}
|
|
}
|
|
|
|
interface RecordedCalls {
|
|
abort: Array<{ sessionID: string; source: string }>
|
|
autoRetry: Array<{ sessionID: string; newModel: string; resolvedAgent: string | undefined; source: string }>
|
|
}
|
|
|
|
function createHelpers(calls: RecordedCalls, resolvedAgentName?: string): AutoRetryHelpers {
|
|
return {
|
|
abortSessionRequest: async (sessionID: string, source: string) => {
|
|
calls.abort.push({ sessionID, source })
|
|
},
|
|
clearSessionFallbackTimeout: () => {},
|
|
scheduleSessionFallbackTimeout: () => {},
|
|
autoRetryWithFallback: async (sessionID, newModel, resolvedAgent, source) => {
|
|
calls.autoRetry.push({ sessionID, newModel, resolvedAgent, source })
|
|
},
|
|
resolveAgentForSessionFromContext: async () => resolvedAgentName,
|
|
cleanupStaleSessions: () => {},
|
|
}
|
|
}
|
|
|
|
const AGENT = "sisyphus-junior"
|
|
const PRIMARY_MODEL = "openai/gpt-5.4-mini"
|
|
const FALLBACK_MODEL = "anthropic/claude-haiku-4-5"
|
|
const PLUGIN_CONFIG_WITH_FALLBACK = {
|
|
agents: {
|
|
[AGENT]: {
|
|
model: PRIMARY_MODEL,
|
|
fallback_models: [{ model: FALLBACK_MODEL }],
|
|
},
|
|
},
|
|
}
|
|
|
|
describe("first-prompt-watchdog", () => {
|
|
beforeEach(() => {
|
|
subagentSessions.clear()
|
|
})
|
|
|
|
afterEach(() => {
|
|
subagentSessions.clear()
|
|
})
|
|
|
|
it("#given a subagent stays silent past the threshold and has a fallback configured #when the watchdog fires #then it aborts the in-flight request and dispatches the fallback model", async () => {
|
|
// given
|
|
const sessionID = "session-silent-subagent"
|
|
subagentSessions.add(sessionID)
|
|
const deps = createDeps(PLUGIN_CONFIG_WITH_FALLBACK)
|
|
const calls: RecordedCalls = { abort: [], autoRetry: [] }
|
|
const helpers = createHelpers(calls, AGENT)
|
|
const watchdog = createFirstPromptWatchdog(deps, helpers, WATCHDOG_MS)
|
|
|
|
// when
|
|
watchdog.onUserMessage(sessionID, PRIMARY_MODEL, AGENT)
|
|
await wait(SAFE_WAIT_AFTER_FIRE_MS)
|
|
|
|
// then
|
|
expect(calls.abort).toEqual([{ sessionID, source: "first-prompt-watchdog" }])
|
|
expect(calls.autoRetry).toHaveLength(1)
|
|
expect(calls.autoRetry[0].sessionID).toBe(sessionID)
|
|
expect(calls.autoRetry[0].newModel).toBe(FALLBACK_MODEL)
|
|
expect(calls.autoRetry[0].source).toBe("first-prompt-watchdog")
|
|
|
|
watchdog.dispose()
|
|
})
|
|
|
|
it("#given a subagent produces assistant text before the threshold #when progress is observed #then the watchdog is cancelled and no fallback is dispatched", async () => {
|
|
// given
|
|
const sessionID = "session-makes-progress"
|
|
subagentSessions.add(sessionID)
|
|
const deps = createDeps(PLUGIN_CONFIG_WITH_FALLBACK)
|
|
const calls: RecordedCalls = { abort: [], autoRetry: [] }
|
|
const helpers = createHelpers(calls, AGENT)
|
|
const watchdog = createFirstPromptWatchdog(deps, helpers, WATCHDOG_MS)
|
|
|
|
// when
|
|
watchdog.onUserMessage(sessionID, PRIMARY_MODEL, AGENT)
|
|
await wait(SAFE_WAIT_BEFORE_FIRE_MS)
|
|
watchdog.onAssistantProgress(sessionID)
|
|
await wait(SAFE_WAIT_AFTER_FIRE_MS)
|
|
|
|
// then
|
|
expect(calls.abort).toEqual([])
|
|
expect(calls.autoRetry).toEqual([])
|
|
|
|
watchdog.dispose()
|
|
})
|
|
|
|
it("#given the session is not a subagent #when a user message is observed #then the watchdog never arms and nothing fires", async () => {
|
|
// given
|
|
const sessionID = "session-not-a-subagent"
|
|
// NOT added to subagentSessions
|
|
const deps = createDeps(PLUGIN_CONFIG_WITH_FALLBACK)
|
|
const calls: RecordedCalls = { abort: [], autoRetry: [] }
|
|
const helpers = createHelpers(calls, AGENT)
|
|
const watchdog = createFirstPromptWatchdog(deps, helpers, WATCHDOG_MS)
|
|
|
|
// when
|
|
watchdog.onUserMessage(sessionID, PRIMARY_MODEL, AGENT)
|
|
await wait(SAFE_WAIT_AFTER_FIRE_MS)
|
|
|
|
// then
|
|
expect(calls.abort).toEqual([])
|
|
expect(calls.autoRetry).toEqual([])
|
|
|
|
watchdog.dispose()
|
|
})
|
|
|
|
it("#given a subagent reaches a terminal session state before the threshold #when onSessionTerminal is called #then the watchdog is cancelled and no fallback is dispatched", async () => {
|
|
// given
|
|
const sessionID = "session-terminated-early"
|
|
subagentSessions.add(sessionID)
|
|
const deps = createDeps(PLUGIN_CONFIG_WITH_FALLBACK)
|
|
const calls: RecordedCalls = { abort: [], autoRetry: [] }
|
|
const helpers = createHelpers(calls, AGENT)
|
|
const watchdog = createFirstPromptWatchdog(deps, helpers, WATCHDOG_MS)
|
|
|
|
// when
|
|
watchdog.onUserMessage(sessionID, PRIMARY_MODEL, AGENT)
|
|
await wait(SAFE_WAIT_BEFORE_FIRE_MS)
|
|
watchdog.onSessionTerminal(sessionID)
|
|
await wait(SAFE_WAIT_AFTER_FIRE_MS)
|
|
|
|
// then
|
|
expect(calls.abort).toEqual([])
|
|
expect(calls.autoRetry).toEqual([])
|
|
|
|
watchdog.dispose()
|
|
})
|
|
|
|
it("#given a subagent silent past the threshold with no fallback configured #when the watchdog fires #then it logs but does not abort or dispatch (lets the existing error-event paths handle it if one arrives later)", async () => {
|
|
// given
|
|
const sessionID = "session-no-fallback"
|
|
subagentSessions.add(sessionID)
|
|
const deps = createDeps({}) // empty pluginConfig → no fallback models
|
|
const calls: RecordedCalls = { abort: [], autoRetry: [] }
|
|
const helpers = createHelpers(calls, AGENT)
|
|
const watchdog = createFirstPromptWatchdog(deps, helpers, WATCHDOG_MS)
|
|
|
|
// when
|
|
watchdog.onUserMessage(sessionID, PRIMARY_MODEL, AGENT)
|
|
await wait(SAFE_WAIT_AFTER_FIRE_MS)
|
|
|
|
// then
|
|
expect(calls.abort).toEqual([])
|
|
expect(calls.autoRetry).toEqual([])
|
|
|
|
watchdog.dispose()
|
|
})
|
|
})
|
|
|
|
interface RecordedWatchdogCalls {
|
|
user: Array<{ sessionID: string; model?: string; agent?: string }>
|
|
progress: string[]
|
|
terminal: string[]
|
|
}
|
|
|
|
function createRecordingWatchdog(calls: RecordedWatchdogCalls): FirstPromptWatchdog {
|
|
return {
|
|
onUserMessage(sessionID, model, agent) {
|
|
calls.user.push({ sessionID, model, agent })
|
|
},
|
|
onAssistantProgress(sessionID) {
|
|
calls.progress.push(sessionID)
|
|
},
|
|
onSessionTerminal(sessionID) {
|
|
calls.terminal.push(sessionID)
|
|
},
|
|
dispose() {},
|
|
}
|
|
}
|
|
|
|
describe("observeEventForWatchdog", () => {
|
|
const sessionID = "session-observed"
|
|
|
|
function freshCalls(): RecordedWatchdogCalls {
|
|
return { user: [], progress: [], terminal: [] }
|
|
}
|
|
|
|
it("#given a message.updated event with role=user #when observed #then onUserMessage is called with sessionID/model/agent", () => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{
|
|
type: "message.updated",
|
|
properties: { info: { sessionID, role: "user", model: "openai/gpt-5.4-mini", agent: "sisyphus-junior" } },
|
|
},
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.user).toEqual([{ sessionID, model: "openai/gpt-5.4-mini", agent: "sisyphus-junior" }])
|
|
expect(calls.progress).toEqual([])
|
|
expect(calls.terminal).toEqual([])
|
|
})
|
|
|
|
it.each([
|
|
["text", { type: "text", text: "hello" }],
|
|
["reasoning", { type: "reasoning", text: "thinking..." }],
|
|
["tool", { type: "tool" }],
|
|
["tool_use", { type: "tool_use", id: "t1", name: "Read" }],
|
|
["tool_result", { type: "tool_result", tool_use_id: "t1" }],
|
|
["tool-call", { type: "tool-call" }],
|
|
["step-start", { type: "step-start" }],
|
|
["file", { type: "file" }],
|
|
])("#given a message.updated assistant event whose only part is type=%s #when observed #then onAssistantProgress is called (model is *working*, not silent)", (_label, part) => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{
|
|
type: "message.updated",
|
|
properties: { info: { sessionID, role: "assistant" }, parts: [part] },
|
|
},
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.progress).toEqual([sessionID])
|
|
})
|
|
|
|
it("#given a message.updated assistant event with parts: [] and no error/finish #when observed #then no progress is signalled (no activity yet)", () => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{
|
|
type: "message.updated",
|
|
properties: { info: { sessionID, role: "assistant" }, parts: [] },
|
|
},
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.progress).toEqual([])
|
|
})
|
|
|
|
it("#given a message.updated assistant event with info.error set #when observed #then onAssistantProgress is called (the existing error-handling path takes over from here)", () => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{
|
|
type: "message.updated",
|
|
properties: { info: { sessionID, role: "assistant", error: { name: "RateLimitError", message: "429" } } },
|
|
},
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.progress).toEqual([sessionID])
|
|
})
|
|
|
|
it("#given a message.updated assistant event with info.finish set #when observed #then onAssistantProgress is called", () => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{
|
|
type: "message.updated",
|
|
properties: { info: { sessionID, role: "assistant", finish: "stop" } },
|
|
},
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.progress).toEqual([sessionID])
|
|
})
|
|
|
|
it.each([["session.idle"], ["session.stop"], ["session.deleted"], ["session.error"]])(
|
|
"#given a %s event #when observed #then onSessionTerminal is called",
|
|
(eventType) => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{ type: eventType, properties: { sessionID } },
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.terminal).toEqual([sessionID])
|
|
},
|
|
)
|
|
|
|
it("#given a session.deleted event whose sessionID is carried under properties.info.id #when observed #then onSessionTerminal is still called (matches event-handler shape)", () => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{ type: "session.deleted", properties: { info: { id: sessionID } } },
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.terminal).toEqual([sessionID])
|
|
})
|
|
|
|
it("#given an unrelated event type #when observed #then no watchdog method is called", () => {
|
|
const calls = freshCalls()
|
|
observeEventForWatchdog(
|
|
{ type: "session.created", properties: { info: { id: sessionID } } },
|
|
createRecordingWatchdog(calls),
|
|
)
|
|
expect(calls.user).toEqual([])
|
|
expect(calls.progress).toEqual([])
|
|
expect(calls.terminal).toEqual([])
|
|
})
|
|
})
|