diff --git a/scripts/test-docker-all.mjs b/scripts/test-docker-all.mjs index 1c4c6815a859..c4da2a142ca6 100644 --- a/scripts/test-docker-all.mjs +++ b/scripts/test-docker-all.mjs @@ -43,6 +43,9 @@ const DEFAULT_PREFLIGHT_RUN_TIMEOUT_MS = 60_000; const CLEANUP_SMOKE_NAME = "cleanup-smoke"; export const SHELL_CAPTURE_MAX_CHARS = 1024 * 1024; export const LOG_TAIL_MAX_BYTES = 1024 * 1024; +const SHELL_TIMEOUT_KILL_GRACE_MS = 10_000; +const SHELL_POST_FORCE_KILL_WAIT_MS = 1_000; +const SHELL_PROCESS_GROUP_EXIT_POLL_MS = 25; const DEFAULT_TIMINGS_FILE = path.join(ROOT_DIR, ".artifacts/docker-tests/lane-timings.json"); const DEFAULT_GITHUB_WORKFLOW = "openclaw-live-and-e2e-checks-reusable.yml"; const IS_MAIN = process.argv[1] @@ -551,7 +554,15 @@ export function dockerPreflightSmokeCommand(arch = process.arch) { return `docker run --rm --platform ${shellQuote(platform)} alpine:3.20 true`; } -export function runShellCommand({ command, env, label, logFile, timeoutMs, noOutputTimeoutMs }) { +export function runShellCommand({ + command, + env, + label, + logFile, + timeoutMs, + noOutputTimeoutMs, + timeoutKillGraceMs = SHELL_TIMEOUT_KILL_GRACE_MS, +}) { return new Promise((resolve) => { const pipeOutput = Boolean(logFile || noOutputTimeoutMs > 0); const child = spawn("bash", ["-c", command], { @@ -564,6 +575,7 @@ export function runShellCommand({ command, env, label, logFile, timeoutMs, noOut let timedOut = false; let noOutputTimedOut = false; let killTimer; + let killAt; let stream; let noOutputTimer; const terminateForTimeout = (message, options = {}) => { @@ -578,7 +590,8 @@ export function runShellCommand({ command, env, label, logFile, timeoutMs, noOut console.error(`==> [${label}] ${message}; sending SIGTERM`); } terminateChild(child, "SIGTERM"); - killTimer = setTimeout(() => terminateChild(child, "SIGKILL"), 10_000); + killAt = Date.now() + timeoutKillGraceMs; + killTimer = setTimeout(() => terminateChild(child, "SIGKILL"), timeoutKillGraceMs); killTimer.unref?.(); }; const resetNoOutputTimer = () => { @@ -627,23 +640,31 @@ export function runShellCommand({ command, env, label, logFile, timeoutMs, noOut if (noOutputTimer) { clearTimeout(noOutputTimer); } + const finish = () => { + if (killTimer) { + clearTimeout(killTimer); + } + killAt = undefined; + activeChildren.delete(child); + const exitCode = typeof status === "number" ? status : signal ? 128 : 1; + if (stream) { + stream.write( + `\n==> [${label}] finished: ${utcStamp()} status=${exitCode}${ + noOutputTimedOut ? " noOutputTimedOut=true" : "" + }\n`, + ); + stream.end(); + } + resolve({ signal, status: exitCode, timedOut, noOutputTimedOut }); + }; if (timedOut) { - terminateChild(child, "SIGKILL"); - } - if (killTimer) { - clearTimeout(killTimer); - } - activeChildren.delete(child); - const exitCode = typeof status === "number" ? status : signal ? 128 : 1; - if (stream) { - stream.write( - `\n==> [${label}] finished: ${utcStamp()} status=${exitCode}${ - noOutputTimedOut ? " noOutputTimedOut=true" : "" - }\n`, + void finishTimedOutShellProcessTree(child, { killAt, timeoutKillGraceMs }).then( + finish, + finish, ); - stream.end(); + return; } - resolve({ signal, status: exitCode, timedOut, noOutputTimedOut }); + finish(); }); }); } @@ -656,7 +677,13 @@ export function appendBoundedShellCapture(current, chunk, maxChars = SHELL_CAPTU return { text: combined.slice(-maxChars), truncated: true }; } -export function runShellCaptureCommand({ command, env, label, timeoutMs }) { +export function runShellCaptureCommand({ + command, + env, + label, + timeoutMs, + timeoutKillGraceMs = SHELL_TIMEOUT_KILL_GRACE_MS, +}) { return new Promise((resolve) => { const child = spawn("bash", ["-c", command], { cwd: ROOT_DIR, @@ -671,12 +698,14 @@ export function runShellCaptureCommand({ command, env, label, timeoutMs }) { let stderrTruncated = false; let timedOut = false; let killTimer; + let killAt; const timeoutTimer = timeoutMs > 0 ? setTimeout(() => { timedOut = true; terminateChild(child, "SIGTERM"); - killTimer = setTimeout(() => terminateChild(child, "SIGKILL"), 10_000); + killAt = Date.now() + timeoutKillGraceMs; + killTimer = setTimeout(() => terminateChild(child, "SIGKILL"), timeoutKillGraceMs); killTimer.unref?.(); }, timeoutMs) : undefined; @@ -695,24 +724,32 @@ export function runShellCaptureCommand({ command, env, label, timeoutMs }) { if (timeoutTimer) { clearTimeout(timeoutTimer); } + const finish = () => { + if (killTimer) { + clearTimeout(killTimer); + } + killAt = undefined; + activeChildren.delete(child); + const exitCode = typeof status === "number" ? status : signal ? 128 : 1; + resolve({ + label, + signal, + status: exitCode, + stderr, + stderrTruncated, + stdout, + stdoutTruncated, + timedOut, + }); + }; if (timedOut) { - terminateChild(child, "SIGKILL"); + void finishTimedOutShellProcessTree(child, { killAt, timeoutKillGraceMs }).then( + finish, + finish, + ); + return; } - if (killTimer) { - clearTimeout(killTimer); - } - activeChildren.delete(child); - const exitCode = typeof status === "number" ? status : signal ? 128 : 1; - resolve({ - label, - signal, - status: exitCode, - stderr, - stderrTruncated, - stdout, - stdoutTruncated, - timedOut, - }); + finish(); }); }); } @@ -1225,6 +1262,47 @@ async function printFailureSummary(failures, tailLines) { } const activeChildren = new Set(); + +function shellProcessGroupAlive(child) { + if (process.platform === "win32" || !child.pid) { + return false; + } + try { + process.kill(-child.pid, 0); + return true; + } catch (error) { + return error?.code === "EPERM"; + } +} + +async function waitForShellProcessGroupExit(child, timeoutMs) { + const deadlineAt = Date.now() + timeoutMs; + while (Date.now() < deadlineAt) { + if (!shellProcessGroupAlive(child)) { + return true; + } + await new Promise((resolvePoll) => { + setTimeout(resolvePoll, SHELL_PROCESS_GROUP_EXIT_POLL_MS); + }); + } + return !shellProcessGroupAlive(child); +} + +async function finishTimedOutShellProcessTree(child, { killAt, timeoutKillGraceMs }) { + if (!shellProcessGroupAlive(child)) { + return; + } + const graceRemainingMs = + killAt === undefined ? timeoutKillGraceMs : Math.max(0, killAt - Date.now()); + if (graceRemainingMs > 0) { + await waitForShellProcessGroupExit(child, graceRemainingMs); + } + if (shellProcessGroupAlive(child)) { + terminateChild(child, "SIGKILL"); + } + await waitForShellProcessGroupExit(child, SHELL_POST_FORCE_KILL_WAIT_MS); +} + function terminateChild(child, signal) { if (process.platform !== "win32" && child.pid) { try { diff --git a/test/scripts/docker-all-scheduler.test.ts b/test/scripts/docker-all-scheduler.test.ts index 770b64861dff..6474340ce117 100644 --- a/test/scripts/docker-all-scheduler.test.ts +++ b/test/scripts/docker-all-scheduler.test.ts @@ -15,10 +15,12 @@ import { LOG_TAIL_MAX_BYTES, parseDockerAllCliArgs, resolveDockerPreflightPlatform, + runShellCaptureCommand, runShellCommand, SHELL_CAPTURE_MAX_CHARS, tailFile, } from "../../scripts/test-docker-all.mjs"; +import { createScriptTestHarness } from "./test-helpers.js"; const limits = { resourceLimits: { @@ -28,6 +30,7 @@ const limits = { weightLimit: 2, }; const posixIt = process.platform === "win32" ? it.skip : it; +const { createTempDir } = createScriptTestHarness(); function activePool({ count = 0, @@ -489,6 +492,7 @@ setInterval(() => {}, 1000); )} ${JSON.stringify(grandchildPidPath)}`, env: process.env, label: "timeout-leader-exits", + timeoutKillGraceMs: 25, timeoutMs: 1_000, }); @@ -507,6 +511,86 @@ setInterval(() => {}, 1000); } }); + posixIt("lets timed-out shell command descendants exit during kill grace", async () => { + const root = createTempDir("openclaw-docker-all-grace-"); + const scriptPath = path.join(root, "leader-exits.mjs"); + const donePath = path.join(root, "done"); + const readyPath = path.join(root, "ready"); + const childScript = [ + "const fs = require('node:fs');", + `fs.writeFileSync(${JSON.stringify(readyPath)}, 'ready');`, + "process.on('SIGTERM', () => {", + ` setTimeout(() => { fs.writeFileSync(${JSON.stringify(donePath)}, 'done'); process.exit(0); }, 75);`, + "});", + "setInterval(() => {}, 1000);", + ].join("\n"); + + writeFileSync( + scriptPath, + ` +import { spawn } from "node:child_process"; + +spawn(process.execPath, ["-e", ${JSON.stringify(childScript)}], { stdio: "ignore" }); +process.on("SIGTERM", () => process.exit(0)); +setInterval(() => {}, 1000); +`, + "utf8", + ); + + const runPromise = runShellCommand({ + command: `exec ${JSON.stringify(process.execPath)} ${JSON.stringify(scriptPath)}`, + env: process.env, + label: "timeout-grace", + timeoutKillGraceMs: 500, + timeoutMs: 500, + }); + + await waitFor(() => existsSync(readyPath)); + const result = await runPromise; + expect(result).toMatchObject({ timedOut: true }); + expect(readFileSync(donePath, "utf8")).toBe("done"); + }); + + posixIt("lets timed-out shell capture descendants exit during kill grace", async () => { + const root = createTempDir("openclaw-docker-all-capture-grace-"); + const scriptPath = path.join(root, "leader-exits.mjs"); + const donePath = path.join(root, "done"); + const readyPath = path.join(root, "ready"); + const childScript = [ + "const fs = require('node:fs');", + `fs.writeFileSync(${JSON.stringify(readyPath)}, 'ready');`, + "process.on('SIGTERM', () => {", + ` setTimeout(() => { fs.writeFileSync(${JSON.stringify(donePath)}, 'done'); process.exit(0); }, 75);`, + "});", + "setInterval(() => {}, 1000);", + ].join("\n"); + + writeFileSync( + scriptPath, + ` +import { spawn } from "node:child_process"; + +spawn(process.execPath, ["-e", ${JSON.stringify(childScript)}], { stdio: "ignore" }); +process.on("SIGTERM", () => process.exit(0)); +setInterval(() => {}, 1000); +`, + "utf8", + ); + + const runPromise = runShellCaptureCommand({ + command: `exec ${JSON.stringify(process.execPath)} ${JSON.stringify(scriptPath)}`, + env: process.env, + label: "capture-timeout-grace", + timeoutKillGraceMs: 500, + timeoutMs: 500, + }); + + await waitFor(() => existsSync(readyPath)); + const result = await runPromise; + expect(result).toMatchObject({ timedOut: true }); + expect(readFileSync(donePath, "utf8")).toBe("done"); + }); + it("describes effective scheduler limits for operator errors", () => { expect(describeDockerSchedulerLimits(2, limits)).toBe( "parallelism=2 weightLimit=2 resources=docker=2 npm=2",