Repository navigation
Classify stalled Codex MCP calls as transport wedges #66303
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -34,6 +34,9 @@ | |
|
|
||
| const { getErrorMessage } = require("./error_helpers.cjs"); | ||
| const fs = require("fs"); | ||
| const { DEFAULT_MCP_CALL_WATCHDOG_MS, MCP_CALL_TRANSPORT_GRACE_MS } = require("./constants.cjs"); | ||
| const { loadCompiledConfig, mergeConfig } = require("./codex_config.cjs"); | ||
| const { parseJsonPrefix } = require("./parse_json_prefix.cjs"); | ||
| const { runProcess, formatDuration, sleep, MIN_POST_RESULT_WATCHDOG_TIMEOUT_MS, DEFAULT_POST_RESULT_WATCHDOG_IDLE_TIMEOUT_MS, MAX_POST_RESULT_WATCHDOG_TIMEOUT_MS, resolvePostResultWatchdogIdleTimeoutMs } = require("./process_runner.cjs"); | ||
| const { runHarnessRetryLoop, shouldSkipForNoopSafeOutputs, shouldStopForNoopSafeOutputs } = require("./harness_retry_runner.cjs"); | ||
| const { | ||
|
|
@@ -92,6 +95,62 @@ const SERVER_ERROR_PATTERN = /InternalServerError|ServiceUnavailableError|500 In | |
| // an identical rejection: retrying only re-bills the turns that succeeded before the failure point. | ||
| const INVALID_REQUEST_ERROR_PATTERN = /invalid_request_error/i; | ||
|
|
||
| function resolveMCPServerToolTimeouts(config, runtimeToolTimeoutSeconds) { | ||
| const configuredServers = config.defaults?.mcp_servers && typeof config.defaults.mcp_servers === "object" ? config.defaults.mcp_servers : {}; | ||
| const defaults = { | ||
| ...config.defaults, | ||
| mcp_servers: Object.fromEntries( | ||
| Object.entries(configuredServers).map(([name, value]) => [ | ||
| name, | ||
| typeof value === "object" && value !== null && !Array.isArray(value) | ||
| ? { ...value, ...(Number.isSafeInteger(runtimeToolTimeoutSeconds) && runtimeToolTimeoutSeconds > 0 ? { tool_timeout_sec: runtimeToolTimeoutSeconds } : {}) } | ||
| : value, | ||
| ]) | ||
| ), | ||
| }; | ||
| const effectiveServers = mergeConfig(defaults, config.overrides || {}).mcp_servers || {}; | ||
| return Object.fromEntries( | ||
| Object.entries(effectiveServers).flatMap(([name, value]) => (typeof value?.tool_timeout_sec === "number" && Number.isSafeInteger(value.tool_timeout_sec) && value.tool_timeout_sec > 0 ? [[name, value.tool_timeout_sec]] : [])) | ||
| ); | ||
| } | ||
|
|
||
| function createMCPCallWatchdog(timeoutMs, now = Date.now) { | ||
| const pending = new Map(); | ||
| function track(eventType, item) { | ||
| if (item?.type !== "mcp_tool_call" || typeof item.id !== "string") return; | ||
| if (eventType === "item.started") { | ||
| const callTimeoutMs = typeof timeoutMs === "function" ? timeoutMs(item) : timeoutMs; | ||
| pending.set(item.id, { startedAt: now(), timeoutMs: Number.isSafeInteger(callTimeoutMs) && callTimeoutMs > 0 ? callTimeoutMs : DEFAULT_MCP_CALL_WATCHDOG_MS }); | ||
| } | ||
| if (eventType === "item.completed" || eventType === "item.failed") pending.delete(item.id); | ||
| } | ||
| return { | ||
| observe(line) { | ||
| let event; | ||
| try { | ||
| event = JSON.parse(line); | ||
| } catch { | ||
| return; | ||
| } | ||
| track(event?.type, event?.item); | ||
| }, | ||
| observePrefix(prefix) { | ||
| const event = parseJsonPrefix(prefix); | ||
| track(event?.type, event?.item); | ||
| }, | ||
| expiredTimeoutMs() { | ||
| const current = now(); | ||
| for (const call of pending.values()) { | ||
| if (current - call.startedAt >= call.timeoutMs) return call.timeoutMs; | ||
| } | ||
| return null; | ||
| }, | ||
| expired() { | ||
| return this.expiredTimeoutMs() !== null; | ||
| }, | ||
| }; | ||
| } | ||
|
|
||
| // Codex's `turn.failed` event nests the actual provider error as a JSON string inside | ||
| // `error.message` (sometimes doubly-nested, e.g. `error.message` -> `{"error": {...}}`). | ||
| // This is a specific, common form of "unsupported model" failure: the configured model does | ||
|
|
@@ -785,6 +844,9 @@ async function main() { | |
| // The deadline includes preflight time and is checked both between and during attempts. | ||
| const softTimeoutGuard = buildSoftTimeoutGuard(driverStartTime); | ||
| const contextRebuildCircuitBreaker = resolveContextRebuildCircuitBreakerConfig(process.env); | ||
| const configuredToolTimeout = Number(codexEnv.GH_AW_TOOL_TIMEOUT); | ||
| const fallbackToolTimeoutMs = Number.isSafeInteger(configuredToolTimeout) && configuredToolTimeout > 0 ? configuredToolTimeout * 1000 + MCP_CALL_TRANSPORT_GRACE_MS : DEFAULT_MCP_CALL_WATCHDOG_MS; | ||
| const serverToolTimeouts = resolveMCPServerToolTimeouts(loadCompiledConfig(), configuredToolTimeout); | ||
| /** @type {string[] | null} */ | ||
| let resumeArgs = null; | ||
| let lastThreadId = ""; | ||
|
|
@@ -808,6 +870,10 @@ async function main() { | |
| getRetryMode: () => (resumeArgs ? `resume ${lastThreadId}` : "fresh run"), | ||
| runAttempt: async attempt => { | ||
| const terminalErrors = []; | ||
| const mcpWatchdog = createMCPCallWatchdog(item => { | ||
| const server = item.server ?? item.server_name ?? item.serverName; | ||
| return serverToolTimeouts[server] ? serverToolTimeouts[server] * 1000 + MCP_CALL_TRANSPORT_GRACE_MS : fallbackToolTimeoutMs; | ||
| }); | ||
| let nextContextCheckAt = Date.now() + contextRebuildCircuitBreaker.pollIntervalMs; | ||
| // Track the file size before this attempt so the watchdog only arms on output | ||
| // written by this attempt, not by a previous retry. | ||
|
|
@@ -823,6 +889,7 @@ async function main() { | |
| stdin: resumeArgs ? resumePrompt : promptInput.stdin, | ||
| maxCollectedOutputBytes: 4 * 1024 * 1024, | ||
| onStdoutLine: line => { | ||
| mcpWatchdog.observe(line); | ||
|
Contributor
There was a problem hiding this comment. [/diagnosing-bugs] 💡 Suggested fixEither (a) have the watchdog treat any dropped/oversized line as a heuristic "activity" signal that resets the deadline rather than silence, or (b) add a regression test simulating an oversized completion line and assert the watchdog does not misclassify a completed call as expired. Right now there's no test for this interaction between the line-size cap and the new @copilot please address this.
Contributor
Author
There was a problem hiding this comment. The duplicated oversized-completion concern is covered by the bounded stdout-prefix lifecycle callback and regression test. Fixed in |
||
| try { | ||
| const event = JSON.parse(line); | ||
| if (event.type === "thread.started" && typeof event.thread_id === "string") lastThreadId = event.thread_id; | ||
|
|
@@ -832,27 +899,36 @@ async function main() { | |
| } | ||
| } catch {} | ||
| }, | ||
| onStdoutLinePrefix: prefix => mcpWatchdog.observePrefix(prefix), | ||
| runtimeGuard: { | ||
| pollIntervalMs: Math.min(contextRebuildCircuitBreaker.pollIntervalMs, 1000), | ||
| termGraceMs: contextRebuildCircuitBreaker.termGraceMs, | ||
| onTriggered: decision => { | ||
| if (decision.event) process.stdout.write(`${JSON.stringify(decision.event)}\n`); | ||
| }, | ||
| shouldTerminate: async () => { | ||
| if (softTimeoutGuard && Date.now() >= softTimeoutGuard.softDeadlineMs) return { terminate: true, reason: "Codex reached the soft execution deadline; stopping to preserve structured output before the step timeout." }; | ||
| const expiredMCPCallTimeoutMs = mcpWatchdog.expiredTimeoutMs(); | ||
| if (expiredMCPCallTimeoutMs !== null) { | ||
| return { | ||
| terminate: true, | ||
| reason: `transport_wedge: MCP tool call timed out after ${Math.round(expiredMCPCallTimeoutMs / 1000)}s`, | ||
| event: { type: "agent.execution", data: { categories: ["transport_wedge"], errorCodes: [], errorTypes: [] } }, | ||
| }; | ||
| } | ||
| if (!contextRebuildCircuitBreaker.enabled) return false; | ||
| if (Date.now() < nextContextCheckAt) return false; | ||
| nextContextCheckAt = Date.now() + contextRebuildCircuitBreaker.pollIntervalMs; | ||
| return evaluateContextRebuildCircuitBreakerForAttempt( | ||
| await readWorkingSetFromTokenUsage(tokenUsagePaths), | ||
| { | ||
| maxRebuildFactor: contextRebuildCircuitBreaker.maxRebuildFactor, | ||
| minCumulativeInputTokens: contextRebuildCircuitBreaker.minCumulativeInputTokens, | ||
| }, | ||
| { safeOutputsPath, safeOutputsByteOffset, logger: log } | ||
| ); | ||
| }, | ||
| }, | ||
| postResultWatchdog: safeOutputsPath | ||
| ? { | ||
| shouldArm: () => | ||
|
|
@@ -1108,6 +1184,8 @@ if (typeof module !== "undefined" && module.exports) { | |
| injectModelFlagAfterExec, | ||
| getCodexModelEnvVar, | ||
| resolvePostResultWatchdogIdleTimeoutMs, | ||
| createMCPCallWatchdog, | ||
| resolveMCPServerToolTimeouts, | ||
| POST_RESULT_WATCHDOG_IDLE_TIMEOUT_MS, | ||
| DEFAULT_POST_RESULT_WATCHDOG_IDLE_TIMEOUT_MS, | ||
| MIN_POST_RESULT_WATCHDOG_TIMEOUT_MS, | ||
|
|
||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -31,6 +31,7 @@ const { extractShellCommandFromToolData } = require("./tool_call_details.cjs"); | |
| const { resolveFailureIssueRepo } = require("./repo_helpers.cjs"); | ||
| const { GITHUB_API_VERSION } = require("./constants.cjs"); | ||
| const { EMPTY_OUTPUT_CAUSES } = require("./empty_output_outcome.cjs"); | ||
| const { isAgentExecutionEvent } = require("./agent_execution.cjs"); | ||
| const fs = require("fs"); | ||
| const https = require("https"); | ||
| const os = require("os"); | ||
|
|
@@ -285,6 +286,7 @@ function parseHTMLCommentMetadata(body, markerKey) { | |
| function buildFailureMatchCategories(options) { | ||
| const categories = []; | ||
|
|
||
| if (options.transportWedge) categories.push("transport_wedge"); | ||
| if (options.isTimedOut) categories.push("timed_out"); | ||
| if (options.hasAssignmentErrors) categories.push("assignment_errors"); | ||
| if (options.hasAssignCopilotFailures) categories.push("assign_copilot_failures"); | ||
|
|
@@ -331,11 +333,32 @@ function buildFailureMatchCategories(options) { | |
| return categories.sort(); | ||
| } | ||
|
|
||
| function hasMCPTransportWedge(sessionContent) { | ||
| if (!sessionContent.includes('"transport_wedge"')) return false; | ||
| return sessionContent.split(/\r?\n/).some(line => { | ||
| try { | ||
|
Contributor
Author
There was a problem hiding this comment. Added an early return when the structured session has no |
||
| const event = JSON.parse(line); | ||
| return isAgentExecutionEvent(event) && event.data.categories.includes("transport_wedge"); | ||
| } catch { | ||
| return false; | ||
| } | ||
| }); | ||
| } | ||
|
|
||
| function getAgentStdioLogPath(agentOutputFile = process.env.GH_AW_AGENT_OUTPUT) { | ||
| return agentOutputFile ? path.join(path.dirname(agentOutputFile), "agent-stdio.log") : "/tmp/gh-aw/agent-stdio.log"; | ||
| } | ||
|
|
||
| function getAgentSessionPath(agentOutputFile = process.env.GH_AW_AGENT_OUTPUT) { | ||
| return agentOutputFile ? path.join(path.dirname(agentOutputFile), "agent-session.jsonl") : "/tmp/gh-aw/agent-session.jsonl"; | ||
| } | ||
|
|
||
| /** | ||
| * Build a precise failure issue title for known failure classes. | ||
| * Falls back to the generic failure title when no specific class matches. | ||
| * @param {Object} options | ||
| * @param {string} options.workflowName | ||
| * @param {boolean} [options.transportWedge] | ||
| * @param {boolean} options.isTimedOut | ||
| * @param {boolean} options.hasMissingSafeOutputs | ||
| * @param {boolean} options.hasReportIncomplete | ||
|
|
@@ -392,6 +415,7 @@ function buildFailureIssueTitle(options) { | |
| const agentName = sanitizeContent(options.copilotAgentNotFound, COPILOT_AGENT_NOT_FOUND_AGENT_MAX_LENGTH).replace(/\s+/g, " ").trim(); | ||
| return `[aw] ${workflowName} could not find configured Copilot agent "${agentName}"`; | ||
| } | ||
| if (options.transportWedge) return `[aw] ${workflowName} stalled on an MCP tool call`; | ||
| if (options.isTimedOut) return `[aw] ${workflowName} timed out`; | ||
| if (options.hasToolDenialsExceeded) return `[aw] ${workflowName} exceeded tool denial limit`; | ||
| if (options.hasCacheMissMisconfiguration) return `[aw] ${workflowName} has cache-memory miss misconfiguration`; | ||
|
|
@@ -4276,10 +4300,19 @@ async function main() { | |
|
|
||
| // Sanitize workflow name for title | ||
| const sanitizedWorkflowName = sanitizeContent(workflowName, { maxLength: 100 }); | ||
| let transportWedge = false; | ||
| if (agentConclusion === "failure") { | ||
| try { | ||
|
Contributor
There was a problem hiding this comment. This reads a hardcoded const agentOutputFile = process.env.GH_AW_AGENT_OUTPUT;
const stdioLogPath = agentOutputFile ? path.join(path.dirname(agentOutputFile), "agent-stdio.log") : "/tmp/gh-aw/agent-stdio.log";If @copilot please address this.
Contributor
Author
There was a problem hiding this comment. The watchdog classifier now reads |
||
| transportWedge = hasMCPTransportWedge(fs.readFileSync(getAgentSessionPath(), "utf8")); | ||
| } catch { | ||
| core.debug("Unified agent session unavailable for MCP watchdog classification"); | ||
| } | ||
| } | ||
| // Only the collector-written root metadata is trusted; report_incomplete.reason is agent-controlled. | ||
| const emptyOutputCause = agentOutputResult.success ? agentOutputResult.collectorEmptyOutputCause : undefined; | ||
| const issueTitle = buildFailureIssueTitle({ | ||
| workflowName: sanitizedWorkflowName, | ||
| transportWedge, | ||
| emptyOutputCause, | ||
| isTimedOut, | ||
| hasMissingSafeOutputs, | ||
|
|
@@ -4308,6 +4341,7 @@ async function main() { | |
| }); | ||
| const failureCategories = buildFailureMatchCategories({ | ||
| agentConclusion, | ||
| transportWedge, | ||
| emptyOutputCause, | ||
| isTimedOut, | ||
| hasAssignmentErrors, | ||
|
|
@@ -5019,6 +5053,9 @@ module.exports = { | |
| CASCADE_ROLLUP_TITLE, | ||
| FAILURE_TITLE_PATTERN, | ||
| buildFailureMatchCategories, | ||
| hasMCPTransportWedge, | ||
| getAgentStdioLogPath, | ||
| getAgentSessionPath, | ||
| buildFailureIssueTitle, | ||
| FAILURE_CATEGORIES_PATH, | ||
| }; | ||
Oops, something went wrong.
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Added bounded stdout-prefix lifecycle metadata handling for oversized JSONL lines, so MCP completion clears the pending call without buffering its large result. Added an oversized-completion regression test. Fixed in
41f97a2.