diff --git a/actions/setup/js/codex_harness.cjs b/actions/setup/js/codex_harness.cjs index 3feb700bd1f..8d15364cccc 100644 --- a/actions/setup/js/codex_harness.cjs +++ b/actions/setup/js/codex_harness.cjs @@ -50,13 +50,14 @@ const { REFLECT_PROVIDER_ALIASES, resolveProviderEndpointFromReflect, } = require("./awf_reflect.cjs"); -const { emitMissingToolPermissionIssue, hasExpectedSafeOutputs, hasNoopInSafeOutputs } = require("./safeoutputs_cli.cjs"); +const { emitInfrastructureIncomplete, emitMissingToolPermissionIssue, hasExpectedSafeOutputs, hasNoopInSafeOutputs } = require("./safeoutputs_cli.cjs"); const { countPermissionDeniedIssues, hasNumerousPermissionDeniedIssues, extractDeniedCommands, buildMissingToolPermissionIssuePayload } = require("./permission_denied_helpers.cjs"); const { detectNonRetryableHarnessGuard, buildSoftTimeoutGuard, emitSoftTimeoutSignal, isAuthenticationFailedError, parseAICreditsExceededProxyRejection } = require("./harness_retry_guard.cjs"); const { MODEL_NOT_SUPPORTED_PATTERN: INVALID_MODEL_ERROR_PATTERN } = require("./detect_agent_errors.cjs"); const { resolveRetryConfig } = require("./harness_retry_config.cjs"); const { applyModelFallback, injectModelFlagAfterExec } = require("./model_fallback.cjs"); const { parseMaxAICreditsExceededFromAuditLog } = require("./ai_credits_context.cjs"); +const { calculateWorkingSetFromJSONL } = require("./working_set_metrics.cjs"); // Pattern to detect OpenAI rate-limit errors. // Matches the JSON error type field ("rate_limit_exceeded"), the HTTP status code @@ -103,6 +104,16 @@ const POST_RESULT_WATCHDOG_IDLE_TIMEOUT_MS = resolvePostResultWatchdogIdleTimeou // A terminal safe-output is any entry whose type is NOT in this set, plus "noop". const SAFE_OUTPUT_NON_TERMINAL_TYPES = new Set(["missing_tool", "report_incomplete"]); +const TOKEN_USAGE_AUDIT_PATH = "/tmp/gh-aw/sandbox/firewall-audit-logs/api-proxy-logs/token-usage.jsonl"; +const TOKEN_USAGE_AWF_AUDIT_PATH = "/tmp/gh-aw/sandbox/firewall/audit/api-proxy-logs/token-usage.jsonl"; +const TOKEN_USAGE_PATH = "/tmp/gh-aw/sandbox/firewall/logs/api-proxy-logs/token-usage.jsonl"; +const TOKEN_USAGE_PATHS = [TOKEN_USAGE_AUDIT_PATH, TOKEN_USAGE_AWF_AUDIT_PATH, TOKEN_USAGE_PATH]; + +const DEFAULT_CONTEXT_REBUILD_FACTOR_LIMIT = 25; +const DEFAULT_CONTEXT_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS = 1000000; +const DEFAULT_CONTEXT_REBUILD_POLL_INTERVAL_MS = 15000; +const DEFAULT_CONTEXT_REBUILD_TERM_GRACE_MS = 5000; + /** * Return the current byte size of the safe-outputs file, or 0 if the file does not * yet exist. Used as a per-attempt baseline so the watchdog only arms on output @@ -519,6 +530,89 @@ function configureCodexProviderFromReflect(options) { } } +/** + * @param {NodeJS.ProcessEnv} [env] + * @returns {{ enabled: boolean, maxRebuildFactor: number, minCumulativeInputTokens: number, pollIntervalMs: number, termGraceMs: number }} + */ +function resolveContextRebuildCircuitBreakerConfig(env = process.env) { + const enabledValue = env.GH_AW_CODEX_CONTEXT_REBUILD_CIRCUIT_BREAKER; + const enabled = enabledValue == null || !/^(0|false|off|no)$/i.test(String(enabledValue).trim()); + const maxRebuildFactorRaw = Number(env.GH_AW_CODEX_MAX_REBUILD_FACTOR); + const minCumulativeInputTokensRaw = Number(env.GH_AW_CODEX_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS); + const pollIntervalRaw = Number(env.GH_AW_CODEX_REBUILD_GUARD_POLL_MS); + const termGraceRaw = Number(env.GH_AW_CODEX_REBUILD_GUARD_TERM_GRACE_MS); + return { + enabled, + // A rebuild factor of exactly 1 means "no rebuild at all", so it is accepted as the + // most aggressive valid threshold; anything below 1 is not a reachable factor. + maxRebuildFactor: Number.isFinite(maxRebuildFactorRaw) && maxRebuildFactorRaw >= 1 ? maxRebuildFactorRaw : DEFAULT_CONTEXT_REBUILD_FACTOR_LIMIT, + minCumulativeInputTokens: Number.isFinite(minCumulativeInputTokensRaw) && Math.floor(minCumulativeInputTokensRaw) >= 1 ? Math.floor(minCumulativeInputTokensRaw) : DEFAULT_CONTEXT_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS, + pollIntervalMs: Number.isFinite(pollIntervalRaw) && pollIntervalRaw > 0 ? Math.max(1000, Math.floor(pollIntervalRaw)) : DEFAULT_CONTEXT_REBUILD_POLL_INTERVAL_MS, + termGraceMs: Number.isFinite(termGraceRaw) && termGraceRaw > 0 ? Math.max(250, Math.floor(termGraceRaw)) : DEFAULT_CONTEXT_REBUILD_TERM_GRACE_MS, + }; +} + +/** + * Returns the working set from the most recently written candidate that yields usable + * measurements. Candidates are ordered by modification time (newest first) so the breaker + * tracks the active run rather than whichever path happens to be listed first, and + * candidates that are missing, empty, or unparseable (`measurement_state` of + * `"unavailable"`) are skipped so a stale or malformed file cannot silently disable it. + * File access is asynchronous to avoid blocking the driver's event loop while polling. + * @param {string[]} paths + * @returns {Promise["workingSet"] | null>} + */ +async function readWorkingSetFromTokenUsage(paths = TOKEN_USAGE_PATHS) { + /** @type {{ path: string, mtimeMs: number }[]} */ + const candidates = []; + for (const candidate of paths) { + if (!candidate) continue; + try { + const stat = await fs.promises.stat(candidate); + if (!stat.isFile() || stat.size <= 0) continue; + candidates.push({ path: candidate, mtimeMs: stat.mtimeMs }); + } catch { + continue; + } + } + candidates.sort((a, b) => b.mtimeMs - a.mtimeMs); + for (const candidate of candidates) { + try { + const content = await fs.promises.readFile(candidate.path, "utf8"); + if (!content.trim()) continue; + const workingSet = calculateWorkingSetFromJSONL(content).workingSet; + if (!workingSet || workingSet.measurement_state === "unavailable") continue; + return workingSet; + } catch { + continue; + } + } + return null; +} + +/** + * @param {ReturnType["workingSet"] | null} workingSet + * @param {{ maxRebuildFactor: number, minCumulativeInputTokens: number }} config + * @returns {{ terminate: boolean, reason: string }} + */ +function evaluateContextRebuildCircuitBreaker(workingSet, config) { + if (!workingSet || typeof workingSet !== "object") { + return { terminate: false, reason: "" }; + } + const rebuildFactor = typeof workingSet.rebuild_factor === "number" && Number.isFinite(workingSet.rebuild_factor) ? workingSet.rebuild_factor : null; + const cumulativeInputTokens = Number.isFinite(workingSet.cumulative_input_tokens) ? Number(workingSet.cumulative_input_tokens) : 0; + if (rebuildFactor == null || rebuildFactor < config.maxRebuildFactor) { + return { terminate: false, reason: "" }; + } + if (!Number.isFinite(cumulativeInputTokens) || cumulativeInputTokens < config.minCumulativeInputTokens) { + return { terminate: false, reason: "" }; + } + return { + terminate: true, + reason: `context-rebuild circuit breaker tripped: rebuild_factor=${rebuildFactor.toFixed(2)} cumulative_input_tokens=${Math.round(cumulativeInputTokens)} thresholds=${config.maxRebuildFactor}/${config.minCumulativeInputTokens}`, + }; +} + /** * Main entry point: run codex with retry logic for transient API failures. * Codex does not support --continue session resumption, so all retries are fresh runs. @@ -618,6 +712,13 @@ async function main() { // deadline the guard fires on the next iteration. Individual attempts are expected to // complete within the SOFT_TIMEOUT_BUFFER_MS window. const softTimeoutGuard = buildSoftTimeoutGuard(driverStartTime); + const contextRebuildCircuitBreaker = resolveContextRebuildCircuitBreakerConfig(process.env); + log( + `context-rebuild circuit breaker: enabled=${contextRebuildCircuitBreaker.enabled}` + + ` maxRebuildFactor=${contextRebuildCircuitBreaker.maxRebuildFactor}` + + ` minCumulativeInputTokens=${contextRebuildCircuitBreaker.minCumulativeInputTokens}` + + ` pollIntervalMs=${contextRebuildCircuitBreaker.pollIntervalMs}` + ); const retryRun = await runHarnessRetryLoop({ maxRetries: MAX_RETRIES, initialDelayMs: INITIAL_DELAY_MS, @@ -640,6 +741,17 @@ async function main() { log, logArgs: safeArgs, env: codexEnv, + runtimeGuard: contextRebuildCircuitBreaker.enabled + ? { + pollIntervalMs: contextRebuildCircuitBreaker.pollIntervalMs, + termGraceMs: contextRebuildCircuitBreaker.termGraceMs, + shouldTerminate: async () => + evaluateContextRebuildCircuitBreaker(await readWorkingSetFromTokenUsage(TOKEN_USAGE_PATHS), { + maxRebuildFactor: contextRebuildCircuitBreaker.maxRebuildFactor, + minCumulativeInputTokens: contextRebuildCircuitBreaker.minCumulativeInputTokens, + }), + } + : undefined, postResultWatchdog: safeOutputsPath ? { shouldArm: () => hasTerminalSafeOutput(safeOutputsPath, safeOutputsByteOffset, { logger: log }), @@ -647,9 +759,23 @@ async function main() { } : undefined, }); + // A guard-terminated run must never be reported as a success: Codex may handle SIGTERM + // and exit cleanly, and `runHarnessRetryLoop` short-circuits on exitCode 0 before + // `handleFailure` runs. Normalize the exit code so the failure handler always sees it. + if (result.runtimeGuardFired && result.exitCode === 0) { + log(`attempt ${attempt + 1}: runtime guard fired but process exited 0 — normalizing exit code to 1`); + return { ...result, exitCode: 1, safeOutputsByteOffset }; + } return { ...result, safeOutputsByteOffset }; }, handleFailure: ({ attempt, result }) => { + if (result.runtimeGuardFired) { + const details = result.runtimeGuardReason || "Codex runtime guard terminated the run after context rebuild thresholds were exceeded."; + emitInfrastructureIncomplete(details, { logger: log }); + log(`attempt ${attempt + 1}: ${details} — not retrying (circuit breaker)`); + return { action: "stop" }; + } + // When the post-result watchdog fired (SIGTERM sent to a hanging Codex process) and the // safe-outputs file contains a terminal result written during this attempt, treat the run // as a success. The agent completed its work and wrote its output — the hang on exit is @@ -673,6 +799,7 @@ async function main() { `attempt ${attempt + 1} failed:` + ` exitCode=${result.exitCode}` + ` watchdogFired=${result.watchdogFired}` + + ` runtimeGuardFired=${result.runtimeGuardFired}` + ` isRateLimitError=${isRateLimit}` + ` isTokenPerMinuteRateLimitError=${isTokenPerMinuteRateLimit}` + ` isAuthenticationFailedError=${isAuthenticationFailed}` + @@ -813,6 +940,14 @@ if (typeof module !== "undefined" && module.exports) { getConfiguredProviderPortFromReflect, validateCodexOpenAIBaseURLFromReflect, configureCodexProviderFromReflect, + resolveContextRebuildCircuitBreakerConfig, + readWorkingSetFromTokenUsage, + evaluateContextRebuildCircuitBreaker, + TOKEN_USAGE_PATHS, + DEFAULT_CONTEXT_REBUILD_FACTOR_LIMIT, + DEFAULT_CONTEXT_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS, + DEFAULT_CONTEXT_REBUILD_POLL_INTERVAL_MS, + DEFAULT_CONTEXT_REBUILD_TERM_GRACE_MS, hasNoopInSafeOutputs, hasExpectedSafeOutputs, resolveRetryConfig, diff --git a/actions/setup/js/codex_harness.test.cjs b/actions/setup/js/codex_harness.test.cjs index b495f898e7c..f57b2ca25f1 100644 --- a/actions/setup/js/codex_harness.test.cjs +++ b/actions/setup/js/codex_harness.test.cjs @@ -29,6 +29,14 @@ const { configureCodexProviderFromReflect, hasNoopInSafeOutputs, resolveRetryConfig, + resolveContextRebuildCircuitBreakerConfig, + evaluateContextRebuildCircuitBreaker, + readWorkingSetFromTokenUsage, + TOKEN_USAGE_PATHS, + DEFAULT_CONTEXT_REBUILD_FACTOR_LIMIT, + DEFAULT_CONTEXT_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS, + DEFAULT_CONTEXT_REBUILD_POLL_INTERVAL_MS, + DEFAULT_CONTEXT_REBUILD_TERM_GRACE_MS, resolvePostResultWatchdogIdleTimeoutMs, DEFAULT_POST_RESULT_WATCHDOG_IDLE_TIMEOUT_MS, MIN_POST_RESULT_WATCHDOG_TIMEOUT_MS, @@ -205,6 +213,134 @@ describe("codex_harness.cjs", () => { }); }); + describe("context rebuild circuit breaker", () => { + it("uses defaults when env overrides are absent or invalid", () => { + const cfg = resolveContextRebuildCircuitBreakerConfig({ + GH_AW_CODEX_MAX_REBUILD_FACTOR: "nope", + GH_AW_CODEX_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS: "-1", + GH_AW_CODEX_REBUILD_GUARD_POLL_MS: "0", + GH_AW_CODEX_REBUILD_GUARD_TERM_GRACE_MS: "0", + }); + expect(cfg.enabled).toBe(true); + expect(cfg.maxRebuildFactor).toBe(DEFAULT_CONTEXT_REBUILD_FACTOR_LIMIT); + expect(cfg.minCumulativeInputTokens).toBe(DEFAULT_CONTEXT_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS); + expect(cfg.pollIntervalMs).toBe(DEFAULT_CONTEXT_REBUILD_POLL_INTERVAL_MS); + expect(cfg.termGraceMs).toBe(DEFAULT_CONTEXT_REBUILD_TERM_GRACE_MS); + }); + + it("supports explicit disable via env", () => { + const cfg = resolveContextRebuildCircuitBreakerConfig({ + GH_AW_CODEX_CONTEXT_REBUILD_CIRCUIT_BREAKER: "false", + }); + expect(cfg.enabled).toBe(false); + }); + + it("trips only when both rebuild factor and cumulative input exceed thresholds", () => { + const config = { maxRebuildFactor: 4, minCumulativeInputTokens: 1000 }; + expect( + evaluateContextRebuildCircuitBreaker( + { + measurement_state: "measured", + rebuild_factor: 4.5, + cumulative_input_tokens: 1400, + peak_input_tokens: 311, + rebuild_excess_tokens: 1089, + invocations: 5, + }, + config + ).terminate + ).toBe(true); + expect( + evaluateContextRebuildCircuitBreaker( + { + measurement_state: "measured", + rebuild_factor: 4.5, + cumulative_input_tokens: 999, + peak_input_tokens: 222, + rebuild_excess_tokens: 777, + invocations: 4, + }, + config + ).terminate + ).toBe(false); + }); + + it("falls back to the default cumulative floor for fractional overrides below one token", () => { + const cfg = resolveContextRebuildCircuitBreakerConfig({ + GH_AW_CODEX_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS: "0.5", + }); + expect(cfg.minCumulativeInputTokens).toBe(DEFAULT_CONTEXT_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS); + }); + + it("does not trip when rebuild_factor is just below the threshold", () => { + const config = { maxRebuildFactor: 4, minCumulativeInputTokens: 1000 }; + expect(evaluateContextRebuildCircuitBreaker({ rebuild_factor: 3.99, cumulative_input_tokens: 2000 }, config).terminate).toBe(false); + }); + + it("trips when rebuild_factor is exactly at the threshold", () => { + const config = { maxRebuildFactor: 4, minCumulativeInputTokens: 1000 }; + expect(evaluateContextRebuildCircuitBreaker({ rebuild_factor: 4, cumulative_input_tokens: 2000 }, config).terminate).toBe(true); + }); + + it("does not trip for null, empty, or non-finite working sets", () => { + const config = { maxRebuildFactor: 4, minCumulativeInputTokens: 1000 }; + expect(evaluateContextRebuildCircuitBreaker(null, config).terminate).toBe(false); + expect(evaluateContextRebuildCircuitBreaker({}, config).terminate).toBe(false); + expect(evaluateContextRebuildCircuitBreaker({ rebuild_factor: Number.NaN, cumulative_input_tokens: 5000 }, config).terminate).toBe(false); + expect(evaluateContextRebuildCircuitBreaker({ rebuild_factor: Number.POSITIVE_INFINITY, cumulative_input_tokens: 5000 }, config).terminate).toBe(false); + expect(evaluateContextRebuildCircuitBreaker({ rebuild_factor: 9, cumulative_input_tokens: Number.NaN }, config).terminate).toBe(false); + }); + + it("accepts a rebuild factor threshold of exactly 1", () => { + expect(resolveContextRebuildCircuitBreakerConfig({ GH_AW_CODEX_MAX_REBUILD_FACTOR: "1" }).maxRebuildFactor).toBe(1); + }); + + it("skips token-usage candidates whose measurements are unavailable", async () => { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), "codex-token-usage-")); + const malformed = path.join(dir, "malformed.jsonl"); + const valid = path.join(dir, "valid.jsonl"); + fs.writeFileSync(malformed, "not json\n{oops\n"); + fs.writeFileSync(valid, `${JSON.stringify({ input_tokens: 100 })}\n${JSON.stringify({ input_tokens: 900 })}\n`); + try { + const workingSet = await readWorkingSetFromTokenUsage([malformed, valid]); + expect(workingSet).not.toBeNull(); + expect(workingSet.measurement_state).toBe("measured"); + expect(workingSet.cumulative_input_tokens).toBe(1000); + } finally { + fs.rmSync(dir, { recursive: true, force: true }); + } + }); + + it("prefers the most recently written token-usage candidate", async () => { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), "codex-token-usage-")); + const stale = path.join(dir, "stale.jsonl"); + const fresh = path.join(dir, "fresh.jsonl"); + fs.writeFileSync(stale, `${JSON.stringify({ input_tokens: 7 })}\n`); + fs.writeFileSync(fresh, `${JSON.stringify({ input_tokens: 500 })}\n${JSON.stringify({ input_tokens: 500 })}\n`); + const now = Date.now() / 1000; + fs.utimesSync(stale, now - 600, now - 600); + fs.utimesSync(fresh, now, now); + try { + // `stale` is listed first, but `fresh` has the newer mtime and must win. + const workingSet = await readWorkingSetFromTokenUsage([stale, fresh]); + expect(workingSet.cumulative_input_tokens).toBe(1000); + } finally { + fs.rmSync(dir, { recursive: true, force: true }); + } + }); + + it("returns null when no candidate yields usable measurements", async () => { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), "codex-token-usage-")); + const malformed = path.join(dir, "malformed.jsonl"); + fs.writeFileSync(malformed, "not json\n"); + try { + expect(await readWorkingSetFromTokenUsage([malformed, path.join(dir, "missing.jsonl")])).toBeNull(); + } finally { + fs.rmSync(dir, { recursive: true, force: true }); + } + }); + }); + describe("OpenAI base URL validation", () => { it("extracts port from URL", () => { expect(extractPortFromURL("http://172.30.0.30:10000")).toBe(10000); @@ -1018,6 +1154,68 @@ process.exit(1);`, }); }); + describe("context rebuild circuit breaker termination", () => { + it("stops and fails the run when the guard fires even if the process exits 0 on SIGTERM", () => { + const tempDir = makeHarnessTempDir("codex-rebuild-breaker-"); + const safeOutputsPath = path.join(tempDir, "safe-outputs.jsonl"); + const stubPath = path.join(tempDir, "stub.cjs"); + const promptPath = path.join(tempDir, "prompt.txt"); + const callsPath = path.join(tempDir, "calls.jsonl"); + const tokenUsagePath = TOKEN_USAGE_PATHS[0]; + // Preserve any pre-existing token-usage log so the test never destroys real data, + // while still always executing its assertions. + const previousTokenUsage = fs.existsSync(tokenUsagePath) ? fs.readFileSync(tokenUsagePath) : null; + fs.mkdirSync(path.dirname(tokenUsagePath), { recursive: true }); + fs.writeFileSync(tokenUsagePath, [100, 100, 100].map(t => JSON.stringify({ input_tokens: t })).join("\n") + "\n", "utf8"); + // Stub stays alive until SIGTERM, then exits cleanly (exit code 0). Without the + // guard-fired normalization this would be misreported as a successful run. + fs.writeFileSync( + stubPath, + `const fs = require("fs"); +const callsPath = process.env.CODEX_HARNESS_STUB_CALLS; +fs.appendFileSync(callsPath, JSON.stringify({args: process.argv.slice(2)}) + "\\n"); +process.stdout.write("rebuilding context...\\n"); +process.on("SIGTERM", () => process.exit(0)); +setInterval(() => {}, 1000);`, + "utf8" + ); + fs.writeFileSync(promptPath, "do the work", "utf8"); + + try { + const result = spawnSync(process.execPath, ["codex_harness.cjs", process.execPath, stubPath, "exec", "--prompt-file", promptPath], { + cwd: path.dirname(require.resolve("./codex_harness.cjs")), + env: { + ...process.env, + CODEX_HARNESS_STUB_CALLS: callsPath, + GH_AW_SAFE_OUTPUTS: safeOutputsPath, + CODEX_API_KEY: "fake-key-for-test", + GH_AW_HARNESS_MAX_RETRIES: "1", + GH_AW_HARNESS_INITIAL_DELAY_MS: "1", + GH_AW_CODEX_MAX_REBUILD_FACTOR: "2", + GH_AW_CODEX_REBUILD_MIN_CUMULATIVE_INPUT_TOKENS: "10", + GH_AW_CODEX_REBUILD_GUARD_POLL_MS: "1000", + GH_AW_CODEX_REBUILD_GUARD_TERM_GRACE_MS: "250", + }, + encoding: "utf8", + timeout: 20000, + }); + const callCount = fs.readFileSync(callsPath, "utf8").trim().split("\n").filter(Boolean).length; + // The circuit breaker stops the retry loop after the first attempt. + expect(callCount).toBe(1); + expect(result.status).toBe(1); + expect(result.stderr).toContain("runtime guard requested termination"); + expect(result.stderr).toContain("normalizing exit code to 1"); + expect(result.stderr).toContain("not retrying (circuit breaker)"); + } finally { + if (previousTokenUsage === null) { + fs.rmSync(tokenUsagePath, { force: true }); + } else { + fs.writeFileSync(tokenUsagePath, previousTokenUsage); + } + } + }); + }); + describe("resolvePostResultWatchdogIdleTimeoutMs", () => { it("uses a 2-minute shared default", () => { expect(DEFAULT_POST_RESULT_WATCHDOG_IDLE_TIMEOUT_MS).toBe(120000); diff --git a/actions/setup/js/harness_retry_runner.cjs b/actions/setup/js/harness_retry_runner.cjs index b750d7a89aa..749be5e455c 100644 --- a/actions/setup/js/harness_retry_runner.cjs +++ b/actions/setup/js/harness_retry_runner.cjs @@ -8,7 +8,7 @@ const { emitSoftTimeoutSignal } = require("./harness_retry_guard.cjs"); /** * `nextDelayMs` overrides the delay before the immediately next attempt; following retries * resume exponential backoff from that delay. - * @typedef {{ exitCode: number, output: string, hasOutput: boolean, durationMs?: number, watchdogFired?: boolean, safeOutputsByteOffset?: number }} HarnessAttemptResult + * @typedef {{ exitCode: number, output: string, hasOutput: boolean, durationMs?: number, watchdogFired?: boolean, runtimeGuardFired?: boolean, runtimeGuardReason?: string, safeOutputsByteOffset?: number }} HarnessAttemptResult * @typedef {{ action: "retry" | "stop", exitCode?: number, nextDelayMs?: number }} HarnessFailureDecision */ diff --git a/actions/setup/js/process_runner.cjs b/actions/setup/js/process_runner.cjs index cc6ee4ff95f..c12b5a2ef48 100644 --- a/actions/setup/js/process_runner.cjs +++ b/actions/setup/js/process_runner.cjs @@ -80,6 +80,11 @@ function sleep(ms) { * pollIntervalMs?: number, * termGraceMs?: number * }, + * runtimeGuard?: { + * shouldTerminate: () => boolean | { terminate: boolean, reason?: string } | Promise, + * pollIntervalMs?: number, + * termGraceMs?: number + * }, * stallWarningIntervalMs?: number * }} options * - command - The executable to run @@ -93,20 +98,22 @@ function sleep(ms) { * GH_AW_HARNESS_STALL_WARNING_MS; 0 disables the warnings. An explicit * caller value is used as-is (not clamped to the environment range) so * tests can use short intervals. - * @returns {Promise<{exitCode: number, output: string, hasOutput: boolean, durationMs: number, watchdogFired: boolean}>} + * @returns {Promise<{exitCode: number, output: string, hasOutput: boolean, durationMs: number, watchdogFired: boolean, runtimeGuardFired: boolean, runtimeGuardReason: string}>} */ -function runProcess({ command, args, attempt, log, logArgs, env, postResultWatchdog, stallWarningIntervalMs }) { +function runProcess({ command, args, attempt, log, logArgs, env, postResultWatchdog, runtimeGuard, stallWarningIntervalMs }) { return new Promise(resolve => { const startTime = Date.now(); // Guard against the promise being settled more than once. On some systems Node // emits 'close' after 'error' (or vice-versa); only the first terminal event should // log and resolve so callers receive a deterministic result. let settled = false; - /** @param {{exitCode: number, output: string, hasOutput: boolean, durationMs: number, watchdogFired: boolean}} result */ + /** @param {{exitCode: number, output: string, hasOutput: boolean, durationMs: number, watchdogFired: boolean, runtimeGuardFired: boolean, runtimeGuardReason: string}} result */ function settle(result) { if (settled) return; settled = true; if (postResultWatchdogTimer) clearInterval(postResultWatchdogTimer); + if (runtimeGuardTimer) clearInterval(runtimeGuardTimer); + if (runtimeGuardKillTimer) clearTimeout(runtimeGuardKillTimer); if (stallWatchdogTimer) clearInterval(stallWatchdogTimer); resolve(result); } @@ -128,15 +135,27 @@ function runProcess({ command, args, attempt, log, logArgs, env, postResultWatch let stderrBytes = 0; let lastActivityAt = Date.now(); let watchdogArmed = false; - let sentSigtermAt = 0; - let sentSigkillAt = 0; + let runtimeGuardFired = false; + let runtimeGuardReason = ""; + // Each termination source tracks its own SIGTERM/SIGKILL timestamps so the two + // grace periods never interfere with one another. + let watchdogSentSigtermAt = 0; + let watchdogSentSigkillAt = 0; + let guardSentSigtermAt = 0; + let guardSentSigkillAt = 0; const watchdogPollIntervalMs = Math.max(50, Number(postResultWatchdog?.pollIntervalMs) || 1000); const watchdogTermGraceMs = Math.max(50, Number(postResultWatchdog?.termGraceMs) || 5000); + const runtimeGuardPollIntervalMs = Math.max(50, Number(runtimeGuard?.pollIntervalMs) || 1000); + const runtimeGuardTermGraceMs = Math.max(50, Number(runtimeGuard?.termGraceMs) || 5000); const rawInactivityTimeout = Number(postResultWatchdog?.inactivityTimeoutMs); const watchdogInactivityTimeoutMs = Number.isFinite(rawInactivityTimeout) && rawInactivityTimeout > 0 ? Math.max(50, rawInactivityTimeout) : 0; /** @type {NodeJS.Timeout | null} */ let postResultWatchdogTimer = null; /** @type {NodeJS.Timeout | null} */ + let runtimeGuardTimer = null; + /** @type {NodeJS.Timeout | null} */ + let runtimeGuardKillTimer = null; + /** @type {NodeJS.Timeout | null} */ let stallWatchdogTimer = null; const stallIntervalMs = Number.isFinite(Number(stallWarningIntervalMs)) ? Math.max(0, Number(stallWarningIntervalMs)) : resolveStallWarningIntervalMs(env ?? process.env); let stallWarnings = 0; @@ -211,20 +230,62 @@ function runProcess({ command, args, attempt, log, logArgs, env, postResultWatch } if (!watchdogArmed) return; const idleMs = Date.now() - lastActivityAt; - if (sentSigtermAt === 0 && idleMs >= watchdogInactivityTimeoutMs) { - sentSigtermAt = Date.now(); + if (watchdogSentSigtermAt === 0 && idleMs >= watchdogInactivityTimeoutMs) { + watchdogSentSigtermAt = Date.now(); log(`attempt ${attempt + 1}: post-result watchdog terminating idle process after ${idleMs}ms (SIGTERM)`); child.kill("SIGTERM"); return; } - if (sentSigtermAt > 0 && sentSigkillAt === 0 && Date.now() - sentSigtermAt >= watchdogTermGraceMs) { - sentSigkillAt = Date.now(); + if (watchdogSentSigtermAt > 0 && watchdogSentSigkillAt === 0 && Date.now() - watchdogSentSigtermAt >= watchdogTermGraceMs) { + watchdogSentSigkillAt = Date.now(); log(`attempt ${attempt + 1}: post-result watchdog forcing process exit after ${watchdogTermGraceMs}ms grace (SIGKILL)`); child.kill("SIGKILL"); } }, watchdogPollIntervalMs); } + if (runtimeGuard && typeof runtimeGuard.shouldTerminate === "function") { + // SIGKILL escalation uses a dedicated timeout rather than the poll interval so the + // grace period is honoured exactly, even when the guard polls infrequently. + const escalateToSigkill = () => { + runtimeGuardKillTimer = null; + if (settled || guardSentSigkillAt > 0) return; + guardSentSigkillAt = Date.now(); + log(`attempt ${attempt + 1}: runtime guard forcing process exit after ${runtimeGuardTermGraceMs}ms grace (SIGKILL)`); + child.kill("SIGKILL"); + }; + // Guards against overlapping polls when `shouldTerminate` is asynchronous. + let guardCheckInFlight = false; + runtimeGuardTimer = setInterval(async () => { + if (settled || guardCheckInFlight) return; + if (runtimeGuardFired) return; + guardCheckInFlight = true; + /** @type {boolean | { terminate: boolean, reason?: string }} */ + let decision = false; + try { + decision = await runtimeGuard.shouldTerminate(); + } catch { + decision = false; + } finally { + guardCheckInFlight = false; + } + if (settled || runtimeGuardFired) return; + const terminate = typeof decision === "boolean" ? decision : !!decision && decision.terminate === true; + if (!terminate) return; + runtimeGuardFired = true; + runtimeGuardReason = typeof decision === "object" && decision !== null && typeof decision.reason === "string" ? decision.reason : ""; + const reasonSuffix = runtimeGuardReason ? ` (${runtimeGuardReason})` : ""; + guardSentSigtermAt = Date.now(); + log(`attempt ${attempt + 1}: runtime guard requested termination${reasonSuffix} (SIGTERM)`); + child.kill("SIGTERM"); + if (runtimeGuardTimer) { + clearInterval(runtimeGuardTimer); + runtimeGuardTimer = null; + } + runtimeGuardKillTimer = setTimeout(escalateToSigkill, runtimeGuardTermGraceMs); + }, runtimeGuardPollIntervalMs); + } + child.on("exit", (code, signal) => { log(`attempt ${attempt + 1}: process exit event` + ` exitCode=${code ?? exitCodeForSignal(signal) ?? 1}` + (signal ? ` signal=${signal}` : "")); }); @@ -237,7 +298,7 @@ function runProcess({ command, args, attempt, log, logArgs, env, postResultWatch // crashes (e.g. SIGSYS) are visible to exit-code-based retry classification even // when the shell/runtime never reports a raw numeric exit status. const exitCode = code ?? exitCodeForSignal(signal) ?? 1; - const watchdogFired = sentSigtermAt > 0; + const watchdogFired = watchdogSentSigtermAt > 0; log( `attempt ${attempt + 1}: process closed` + ` exitCode=${exitCode}` + @@ -245,9 +306,10 @@ function runProcess({ command, args, attempt, log, logArgs, env, postResultWatch ` duration=${formatDuration(durationMs)}` + ` stdout=${stdoutBytes}B stderr=${stderrBytes}B hasOutput=${hasOutput}` + (watchdogFired ? ` watchdogFired=true` : "") + + (runtimeGuardFired ? ` runtimeGuardFired=true` : "") + (stallWarnings > 0 ? ` stallWarnings=${stallWarnings}` : "") ); - settle({ exitCode, output: collectedOutput, hasOutput, durationMs, watchdogFired }); + settle({ exitCode, output: collectedOutput, hasOutput, durationMs, watchdogFired, runtimeGuardFired, runtimeGuardReason }); }); child.on("error", err => { @@ -263,6 +325,8 @@ function runProcess({ command, args, attempt, log, logArgs, env, postResultWatch hasOutput, durationMs, watchdogFired: false, + runtimeGuardFired: false, + runtimeGuardReason: "", }); }); }); diff --git a/actions/setup/js/process_runner.test.cjs b/actions/setup/js/process_runner.test.cjs index df74926236e..139dff52d1f 100644 --- a/actions/setup/js/process_runner.test.cjs +++ b/actions/setup/js/process_runner.test.cjs @@ -291,6 +291,84 @@ describe("process_runner.cjs", () => { expect(logs.some(line => line.includes("post-result watchdog terminating idle process"))).toBe(false); }); + it("terminates a running process when runtime guard requests it", async () => { + const logs = []; + let checks = 0; + const result = await runProcess({ + command: process.execPath, + args: ["-e", "setInterval(() => process.stdout.write('.'), 20);"], + attempt: 0, + log: msg => logs.push(msg), + runtimeGuard: { + shouldTerminate: () => { + checks += 1; + if (checks < 3) return false; + return { terminate: true, reason: "test guard tripped" }; + }, + pollIntervalMs: 25, + termGraceMs: 200, + }, + }); + expect(result.exitCode).not.toBe(0); + expect(result.runtimeGuardFired).toBe(true); + expect(result.runtimeGuardReason).toContain("test guard tripped"); + expect(result.watchdogFired).toBe(false); + expect(logs.some(line => line.includes("runtime guard requested termination"))).toBe(true); + }); + + it("escalates to SIGKILL after the grace period even when the poll interval is longer", async () => { + const logs = []; + const started = Date.now(); + const result = await runProcess({ + command: process.execPath, + // Ignores SIGTERM, so only SIGKILL can stop it. + args: ["-e", "process.on('SIGTERM', () => {}); setInterval(() => {}, 50);"], + attempt: 0, + log: msg => logs.push(msg), + runtimeGuard: { + shouldTerminate: () => ({ terminate: true, reason: "kill escalation test" }), + pollIntervalMs: 50, + // Grace period is far shorter than the poll interval below would allow. + termGraceMs: 150, + }, + }); + const elapsed = Date.now() - started; + expect(result.runtimeGuardFired).toBe(true); + expect(result.exitCode).not.toBe(0); + expect(logs.some(line => line.includes("runtime guard forcing process exit after 150ms grace (SIGKILL)"))).toBe(true); + // Without the dedicated escalation timer this would take multiple poll cycles. + expect(elapsed).toBeLessThan(5000); + }); + + it("supports an asynchronous shouldTerminate without overlapping polls", async () => { + const logs = []; + let inFlight = 0; + let maxInFlight = 0; + let checks = 0; + const result = await runProcess({ + command: process.execPath, + args: ["-e", "setInterval(() => process.stdout.write('.'), 20);"], + attempt: 0, + log: msg => logs.push(msg), + runtimeGuard: { + shouldTerminate: async () => { + inFlight += 1; + maxInFlight = Math.max(maxInFlight, inFlight); + await new Promise(resolve => setTimeout(resolve, 60)); + inFlight -= 1; + checks += 1; + return checks < 2 ? false : { terminate: true, reason: "async guard tripped" }; + }, + pollIntervalMs: 25, + termGraceMs: 200, + }, + }); + expect(maxInFlight).toBe(1); + expect(result.runtimeGuardFired).toBe(true); + expect(result.runtimeGuardReason).toContain("async guard tripped"); + expect(result.watchdogFired).toBe(false); + }); + it("does not enable watchdog when inactivityTimeoutMs is missing or invalid", async () => { const logs = []; const result = await runProcess({