diff --git a/.claude-plugin/marketplace.json b/.claude-plugin/marketplace.json index 016dedc80..03af6b846 100644 --- a/.claude-plugin/marketplace.json +++ b/.claude-plugin/marketplace.json @@ -5,13 +5,13 @@ }, "metadata": { "description": "Codex plugins to use in Claude Code for delegation and code review.", - "version": "1.0.37" + "version": "1.0.38" }, "plugins": [ { "name": "codex", "description": "Use Codex from Claude Code to review code or delegate tasks.", - "version": "1.0.37", + "version": "1.0.38", "author": { "name": "OpenAI" }, diff --git a/package-lock.json b/package-lock.json index c800e1779..89d5ab90a 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "@openai/codex-plugin-cc", - "version": "1.0.37", + "version": "1.0.38", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "@openai/codex-plugin-cc", - "version": "1.0.37", + "version": "1.0.38", "license": "Apache-2.0", "devDependencies": { "@types/node": "^25.5.0", diff --git a/package.json b/package.json index ea05cbc06..e51e6332a 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@openai/codex-plugin-cc", - "version": "1.0.37", + "version": "1.0.38", "private": true, "type": "module", "description": "Use Codex from Claude Code to review code or delegate tasks.", diff --git a/plugins/codex/.claude-plugin/plugin.json b/plugins/codex/.claude-plugin/plugin.json index 0de326a56..483f78bb5 100644 --- a/plugins/codex/.claude-plugin/plugin.json +++ b/plugins/codex/.claude-plugin/plugin.json @@ -1,6 +1,6 @@ { "name": "codex", - "version": "1.0.37", + "version": "1.0.38", "description": "Use Codex from Claude Code to review code or delegate tasks.", "author": { "name": "OpenAI" diff --git a/plugins/codex/scripts/lib/codex.mjs b/plugins/codex/scripts/lib/codex.mjs index d240f2a4b..b4c30624a 100644 --- a/plugins/codex/scripts/lib/codex.mjs +++ b/plugins/codex/scripts/lib/codex.mjs @@ -26,9 +26,11 @@ * activeSubagentTurns: Set, * completionTimer: ReturnType | null, * activityTimer: ReturnType | null, + * lastActivityAt: number | null, + * activityCount: number, * stallCleanup: Promise | null, * stalled: boolean, - * activeTools: Map | null }>, + * activeTools: Map | null, armedAt: number | null }>, * lastAgentMessage: string, * reviewText: string, * reasoningSummary: string[], @@ -416,6 +418,8 @@ function createTurnCaptureState(threadId, options = {}) { activeSubagentTurns: new Set(), completionTimer: null, activityTimer: null, + lastActivityAt: null, + activityCount: 0, stallCleanup: null, stalled: false, activeTools: new Map(), @@ -479,12 +483,20 @@ function trackToolStart(state, client, threadId, item, label, maxInFlightMs) { } const key = activeToolKey(threadId, item?.id); removeActiveTool(state, key); - const entry = { threadId: threadId ?? null, itemId: item?.id ?? null, toolClass: cls, label, deadlineTimer: null }; + const entry = { + threadId: threadId ?? null, + itemId: item?.id ?? null, + toolClass: cls, + label, + deadlineTimer: null, + armedAt: null + }; state.activeTools.set(key, entry); if (cls === "quick" && !state.completed && maxInFlightMs > 0 && Number.isFinite(maxInFlightMs)) { + entry.armedAt = Date.now(); entry.deadlineTimer = setTimeout(() => { entry.deadlineTimer = null; - state.stallCleanup = handleStall(state, client, maxInFlightMs, "tool-max", entry.label); + state.stallCleanup = handleStall(state, client, maxInFlightMs, "tool-max", entry.label, entry.armedAt); }, maxInFlightMs); entry.deadlineTimer.unref?.(); } @@ -643,21 +655,73 @@ async function interruptTurnWithTimeout(client, threadId, turnId) { } } -async function handleStall(state, client, stallTimeoutMs, stallMode, itemLabel = null) { +function formatStallDuration(ms) { + if (!Number.isFinite(ms)) { + return null; + } + if (ms < 1000) { + return `${Math.max(0, Math.round(ms))}ms`; + } + return `${Math.round(ms / 1000)}s`; +} + +// Timings below are deliberately wall-clock (`Date.now`), not monotonic. `setTimeout` runs on loop +// time, which stops while the machine sleeps, so a monotonic measurement would always agree with the +// budget and hide the very overshoot this reports. The gap between the two clocks is the diagnostic: +// wall-clock elapsed far above the budget means the timer lost time it could not observe. +async function handleStall(state, client, stallTimeoutMs, stallMode, itemLabel = null, armedAt = null) { if (state.completed) { return; } state.stalled = true; - const seconds = Math.round(stallTimeoutMs / 1000); + const now = Date.now(); + const budgetSeconds = Math.round(stallTimeoutMs / 1000); + const measuredMs = + stallMode === "tool-max" + ? Number.isFinite(armedAt) + ? now - armedAt + : null + : Number.isFinite(state.lastActivityAt) + ? now - state.lastActivityAt + : null; + const lateMs = Number.isFinite(armedAt) && Number.isFinite(stallTimeoutMs) + ? now - (armedAt + stallTimeoutMs) + : null; const labels = itemLabel ? [itemLabel] : activeToolLabels(state); const itemDetail = labels.length ? ` while "${labels.join(", ")}" was in flight` : ""; const modeDetail = stallMode === "tool" ? "tool-in-flight" : stallMode === "tool-max" ? "tool-max-duration" : "idle"; const reason = stallMode === "tool-max" - ? `in flight for ${seconds}s without completing (exceeded max tool duration)` - : `no activity for ${seconds}s`; - const message = `Codex turn stalled (${modeDetail}): ${reason}${itemDetail}. Interrupting and aborting the turn.`; + ? `in flight for ${budgetSeconds}s without completing (exceeded max tool duration)` + : `no activity for ${budgetSeconds}s`; + const detailParts = []; + const budget = formatStallDuration(stallTimeoutMs); + if (budget) { + detailParts.push(`budget ${budget}`); + } + if (Number.isFinite(measuredMs)) { + if (stallMode === "tool-max") { + detailParts.push(`measured ${formatStallDuration(measuredMs)} since the tool deadline was armed`); + } else { + let activityDetail = `measured ${formatStallDuration(measuredMs)} since the last of ${state.activityCount} activity events`; + if (Number.isFinite(state.lastActivityAt)) { + activityDetail += ` at ${new Date(state.lastActivityAt).toISOString()}`; + } + detailParts.push(activityDetail); + } + } + if (stallMode === "tool-max") { + detailParts.push(`${state.activityCount} activity events`); + if (Number.isFinite(state.lastActivityAt)) { + detailParts.push(`last activity at ${new Date(state.lastActivityAt).toISOString()}`); + } + } + if (Number.isFinite(lateMs) && lateMs > 1000) { + detailParts.push(`timer fired ${formatStallDuration(lateMs)} late`); + } + const detail = detailParts.length ? ` [${detailParts.join("; ")}]` : ""; + const message = `Codex turn stalled (${modeDetail}): ${reason}${itemDetail}${detail}. Interrupting and aborting the turn.`; state.error ??= { message }; emitLogEvent(state.onProgress, { message, @@ -682,6 +746,9 @@ function bumpActivity(state, client, stallTimeouts) { return; } + state.lastActivityAt = Date.now(); + state.activityCount += 1; + // A single global inactivity timer covers the whole turn. Use the short tool budget while any // quick tool is in flight; otherwise (only long tools, or none) fall back to the generous turn // backstop, since long tools (shell commands, subagent collaborations) can run long and silent. @@ -690,9 +757,10 @@ function bumpActivity(state, client, stallTimeouts) { clearActivityTimer(state); if (stallTimeoutMs > 0 && Number.isFinite(stallTimeoutMs)) { + const armedAt = Date.now(); state.activityTimer = setTimeout(() => { - state.activityTimer = null; - state.stallCleanup = handleStall(state, client, stallTimeoutMs, stallMode); + clearActivityTimer(state); + state.stallCleanup = handleStall(state, client, stallTimeoutMs, stallMode, null, armedAt); }, stallTimeoutMs); state.activityTimer.unref?.(); } diff --git a/tests/runtime.test.mjs b/tests/runtime.test.mjs index 14e3e768d..c548fce7a 100644 --- a/tests/runtime.test.mjs +++ b/tests/runtime.test.mjs @@ -18,6 +18,7 @@ import { } from "../plugins/codex/scripts/lib/broker-lifecycle.mjs"; import { parseBrokerEndpoint } from "../plugins/codex/scripts/lib/broker-endpoint.mjs"; import { CodexAppServerClient } from "../plugins/codex/scripts/lib/app-server.mjs"; +import { runAppServerTurn } from "../plugins/codex/scripts/lib/codex.mjs"; import { getProcessStartTime } from "../plugins/codex/scripts/lib/process.mjs"; import { resolveClaudeSessionPath, @@ -3087,6 +3088,68 @@ test("task watchdog lets idle reasoning exceed tool budget and stalls at turn ba assert.match(storedPayload.storedJob.rendered, /Codex turn stalled \(idle\)/i); }); +test("in-process idle watchdog reports measured oversleep and late firing", async (t) => { + const repo = makeTempDir(); + const binDir = makeTempDir(); + installFakeCodex(binDir, "idle-hung-turn"); + initGitRepo(repo); + + const stallTimeoutMs = 100; + const toolStallTimeoutMs = 50; + const previousPath = process.env.PATH; + const previousTurnStallTimeout = process.env.CODEX_TURN_STALL_TIMEOUT_MS; + const previousToolStallTimeout = process.env.CODEX_TOOL_STALL_TIMEOUT_MS; + process.env.PATH = buildEnv(binDir).PATH; + process.env.CODEX_TURN_STALL_TIMEOUT_MS = String(stallTimeoutMs); + process.env.CODEX_TOOL_STALL_TIMEOUT_MS = String(toolStallTimeoutMs); + t.after(() => { + if (previousPath === undefined) { + delete process.env.PATH; + } else { + process.env.PATH = previousPath; + } + if (previousTurnStallTimeout === undefined) { + delete process.env.CODEX_TURN_STALL_TIMEOUT_MS; + } else { + process.env.CODEX_TURN_STALL_TIMEOUT_MS = previousTurnStallTimeout; + } + if (previousToolStallTimeout === undefined) { + delete process.env.CODEX_TOOL_STALL_TIMEOUT_MS; + } else { + process.env.CODEX_TOOL_STALL_TIMEOUT_MS = previousToolStallTimeout; + } + }); + + let blockTimer = null; + t.after(() => clearTimeout(blockTimer)); + + const result = await runAppServerTurn(repo, { + prompt: "think without tools", + sandbox: "read-only", + onProgress: (update) => { + const message = typeof update === "string" ? update : update?.message; + if (!blockTimer && message?.startsWith("Turn started")) { + blockTimer = setTimeout(() => { + const blockUntil = Date.now() + 1500; + while (Date.now() < blockUntil) { + // Deliberately starve the event loop past the watchdog deadline. + } + }, 50); + } + } + }); + + const failureMessage = result.error?.message ?? ""; + assert.notEqual(result.status, 0); + assert.match(failureMessage, /Codex turn stalled \(idle\)/); + const measured = failureMessage.match(/measured (\d+)(ms|s)/); + assert.ok(measured, failureMessage); + const measuredMs = Number(measured[1]) * (measured[2] === "s" ? 1000 : 1); + assert.ok(measuredMs > stallTimeoutMs * 2, failureMessage); + assert.match(failureMessage, /since the last of \d+ activity events at \d{4}-\d{2}-\d{2}T[^ ]+Z/); + assert.match(failureMessage, /timer fired (\d+)(ms|s) late/); +}); + test("review rejects focus text because it is native-review only", () => { const repo = makeTempDir(); const binDir = makeTempDir();