From cb9ccfe708e97867ac84ea842743f8efeba0f572 Mon Sep 17 00:00:00 2001 From: Sebastien Tardif Date: Mon, 7 Sep 2026 12:12:42 -0700 Subject: [PATCH 1/2] fix: time out hung capture and profile child processes Kill mock-SDK capture after 30s and classify the failure as capture-timeout so a register() that never settles cannot hang plugin-inspector capture. Profiled subprocesses now share that budget, get killed on expiry, cap stdout/stderr, and clear poll timers on every path. Flush stdout before process.exit. Escalate from SIGTERM to SIGKILL after the grace window. Replayed onto upstream/main 92db8c5. Signed-off-by: Sebastien Tardif --- README.md | 11 +++ src/flush-write.js | 21 ++++ src/import-loop-profile.js | 4 + src/inspector.js | 157 +++++++++++++++++++++++++++--- src/mock-sdk-capture-runner.js | 16 +-- src/process-profile.js | 153 ++++++++++++++++++++++------- src/runtime-profile.js | 3 + test/capture-timeout.test.js | 172 +++++++++++++++++++++++++++++++++ test/flush-write.test.js | 32 ++++++ test/process-profile.test.js | 122 +++++++++++++++++++++++ 10 files changed, 634 insertions(+), 57 deletions(-) create mode 100644 src/flush-write.js create mode 100644 test/capture-timeout.test.js create mode 100644 test/flush-write.test.js create mode 100644 test/process-profile.test.js diff --git a/README.md b/README.md index a7eb6cb..5ee0bf1 100644 --- a/README.md +++ b/README.md @@ -250,6 +250,17 @@ Capture one entrypoint directly: plugin-inspector capture ./dist/index.js --mock-sdk --allow-execute ``` +Mock-SDK capture runs the plugin in a child process. If `register()` never +settles, or the child never exits, the inspector kills that child after 30 +seconds and reports a `capture-timeout` failure instead of hanging. Override +the budget with `timeoutMs` or `PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS`. + +Import-loop and runtime profiles use the same 30-second child budget so a +command that never exits cannot stall `buildImportLoopProfile` or +`buildRuntimeProfile`. Override those with `timeoutMs` or +`PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS`. Profiled stdout and stderr are capped +at 1 MB. + ## CI `plugin-inspector ci` writes the normal compatibility report plus CI-native diff --git a/src/flush-write.js b/src/flush-write.js new file mode 100644 index 0000000..a3525b7 --- /dev/null +++ b/src/flush-write.js @@ -0,0 +1,21 @@ +export function flushWrite(write, text) { + return new Promise((resolve, reject) => { + let settled = false; + const done = (err) => { + if (settled) { + return; + } + settled = true; + if (err) { + reject(err); + return; + } + resolve(); + }; + try { + write(text, done); + } catch (err) { + done(err); + } + }); +} diff --git a/src/import-loop-profile.js b/src/import-loop-profile.js index 98a96ab..821aa04 100644 --- a/src/import-loop-profile.js +++ b/src/import-loop-profile.js @@ -261,12 +261,16 @@ async function runCaptureSample(options) { args: command.args, cwd: command.cwd ?? options.rootDir, env: { ...process.env, ...command.env }, + timeoutMs: options.timeoutMs, + maxOutputBytes: options.maxOutputBytes, + killGraceMs: options.killGraceMs, }); const output = profile.exitCode === 0 ? await readCaptureOutput(outputPath) : null; return { index: options.index, exitCode: profile.exitCode, + timedOut: profile.timedOut === true, status: output?.status ?? "failed", capturedCount: output?.captured?.length ?? 0, openClawLifecycle: output?.openClawLifecycle ?? null, diff --git a/src/inspector.js b/src/inspector.js index 5433413..3a85fb1 100644 --- a/src/inspector.js +++ b/src/inspector.js @@ -1,10 +1,9 @@ import { existsSync } from "node:fs"; -import { execFile } from "node:child_process"; +import { spawn } from "node:child_process"; import { readdir, readFile } from "node:fs/promises"; import * as nodeModule from "node:module"; import path from "node:path"; import { fileURLToPath, pathToFileURL } from "node:url"; -import { promisify } from "node:util"; import { createCaptureApi } from "./capture-api.js"; import { captureApiOptionsForPlugin } from "./capture-config.js"; import { fixtureCheckoutPath, fixtureSourceRoot } from "./config.js"; @@ -14,10 +13,11 @@ import { prepareOpenClawTarget, resolveOpenClawTargetVersion } from "./openclaw- import { buildCompatibilityReport, buildReport } from "./report.js"; import { inspectSdkDeprecations } from "./sdk-deprecation-rules.js"; -const execFileAsync = promisify(execFile); const pluginFactoryNames = "defineBundledChannelEntry|defineChannelPluginEntry|createChatChannelPlugin|definePluginEntry"; // Bundlers emit unbound calls as (0, sdk.factory)(...), including inline require receivers. const compiledFactoryCall = new RegExp(String.raw`\(\s*0\s*,\s*(?:require\s*\(\s*(?:"[^"\r\n]*"|'[^'\r\n]*')\s*\)|[$A-Z_a-z][$\w]*)(?:\s*\.\s*[$A-Z_a-z][$\w]*)*\s*\.\s*(${pluginFactoryNames})\s*\)\s*\(`, "dg"); +export const defaultCaptureTimeoutMs = 30_000; +export const defaultCaptureKillGraceMs = 1_000; const registrationEquivalents = new Map([ ["registerChannel", new Set(["createChatChannelPlugin", "defineBundledChannelEntry", "defineChannelPluginEntry", "registerChannel"])], ]); @@ -233,29 +233,148 @@ export async function captureEntrypointWithMockSdk(entrypoint, options = {}) { pluginRoot: options.pluginRoot, apiOptions: options.apiOptions, }; + const timeoutMs = resolveCaptureTimeoutMs(options); + const killGraceMs = resolveCaptureKillGraceMs(options); try { - const { stdout } = await execFileAsync( - process.execPath, - ["--no-warnings", "--preserve-symlinks", runnerPath, JSON.stringify(payload)], - { - cwd: options.cwd ?? process.cwd(), - env: { - ...process.env, - ...(options.env ?? {}), - }, - maxBuffer: 1024 * 1024 * 10, + const { stdout } = await runMockSdkCaptureChild({ + runnerPath, + payload, + cwd: options.cwd ?? process.cwd(), + env: { + ...process.env, + ...(options.env ?? {}), }, - ); + timeoutMs, + killGraceMs, + maxBuffer: 1024 * 1024 * 10, + }); return JSON.parse(stdout); } catch (error) { + error.timeoutMs = timeoutMs; const captured = parseCaptureResultFromStdout(error?.stdout); - if (captured) { + if (captured && !isChildTimeoutError(error)) { return captured; } throw classifyMockSdkCaptureError(error); } } +export function resolveCaptureTimeoutMs(options = {}) { + if (Number.isFinite(options.timeoutMs) && options.timeoutMs > 0) { + return options.timeoutMs; + } + const fromEnv = Number.parseInt(String(options.env?.PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS ?? process.env.PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS ?? ""), 10); + if (Number.isFinite(fromEnv) && fromEnv > 0) { + return fromEnv; + } + return defaultCaptureTimeoutMs; +} + +export function resolveCaptureKillGraceMs(options = {}) { + if (Number.isFinite(options.killGraceMs) && options.killGraceMs >= 0) { + return options.killGraceMs; + } + const fromEnv = Number.parseInt( + String(options.env?.PLUGIN_INSPECTOR_CAPTURE_KILL_GRACE_MS ?? process.env.PLUGIN_INSPECTOR_CAPTURE_KILL_GRACE_MS ?? ""), + 10, + ); + if (Number.isFinite(fromEnv) && fromEnv >= 0) { + return fromEnv; + } + return defaultCaptureKillGraceMs; +} + +function runMockSdkCaptureChild({ runnerPath, payload, cwd, env, timeoutMs, killGraceMs, maxBuffer }) { + return new Promise((resolve, reject) => { + const child = spawn( + process.execPath, + ["--no-warnings", "--preserve-symlinks", runnerPath, JSON.stringify(payload)], + { cwd, env, stdio: ["ignore", "pipe", "pipe"] }, + ); + const stdoutChunks = []; + const stderrChunks = []; + let stdoutBytes = 0; + let settled = false; + let timedOut = false; + let timeoutId; + let forceKillId; + + const finish = (err, result) => { + if (settled) { + return; + } + settled = true; + if (timeoutId !== undefined) { + clearTimeout(timeoutId); + } + if (forceKillId !== undefined) { + clearTimeout(forceKillId); + } + if (err) { + reject(err); + return; + } + resolve(result); + }; + + child.stdout?.on("data", (chunk) => { + stdoutBytes += chunk.length; + if (stdoutBytes <= maxBuffer) { + stdoutChunks.push(chunk); + } + }); + child.stderr?.on("data", (chunk) => { + stderrChunks.push(chunk); + }); + child.on("error", (error) => finish(error)); + child.on("exit", (code, signal) => { + const stdout = Buffer.concat(stdoutChunks).toString("utf8"); + const stderr = Buffer.concat(stderrChunks).toString("utf8"); + if (timedOut) { + finish( + Object.assign(new Error("Command failed: node mock-sdk-capture-runner.js"), { + killed: true, + signal: signal ?? "SIGKILL", + code, + stdout, + stderr, + }), + ); + return; + } + if (code === 0) { + finish(null, { stdout, stderr }); + return; + } + finish( + Object.assign(new Error("Command failed: node mock-sdk-capture-runner.js"), { + killed: false, + signal, + code, + stdout, + stderr, + }), + ); + }); + + if (timeoutMs > 0) { + timeoutId = setTimeout(() => { + timedOut = true; + child.kill("SIGTERM"); + forceKillId = setTimeout(() => { + if (child.exitCode === null && child.signalCode === null) { + child.kill("SIGKILL"); + } + }, killGraceMs); + }, timeoutMs); + } + }); +} + +export function isChildTimeoutError(error) { + return error?.killed === true && (error.signal === "SIGTERM" || error.signal === "SIGKILL"); +} + function parseCaptureResultFromStdout(stdout) { if (!stdout) { return null; @@ -277,6 +396,14 @@ function parseCaptureResultFromStdout(stdout) { } export function classifyMockSdkCaptureError(error) { + if (isChildTimeoutError(error)) { + const timeoutMs = Number.isFinite(error?.timeoutMs) ? error.timeoutMs : defaultCaptureTimeoutMs; + return enrichCaptureError(error, { + message: `Mock SDK capture timed out after ${timeoutMs}ms`, + failureClass: "capture-timeout", + }); + } + const rawMessage = [error?.stderr, error?.stdout, error?.message].filter(Boolean).join("\n"); const missingExport = rawMessage.match(/does not provide an export named ['"]([^'"]+)['"]/)?.[1]; if (missingExport) { diff --git a/src/mock-sdk-capture-runner.js b/src/mock-sdk-capture-runner.js index c480864..1607522 100644 --- a/src/mock-sdk-capture-runner.js +++ b/src/mock-sdk-capture-runner.js @@ -7,6 +7,7 @@ import path from "node:path"; import { pathToFileURL } from "node:url"; import { createCaptureApi } from "./capture-api.js"; import { captureApiOptionsForPlugin } from "./capture-config.js"; +import { flushWrite } from "./flush-write.js"; import { createMockSdkPackage } from "./sdk-mock.js"; const options = JSON.parse(process.argv[2] ?? "{}"); @@ -14,13 +15,14 @@ let activeOutputCapture = null; try { const result = await run(options); - writeRunnerStdout(`${JSON.stringify(result, null, 2)}\n`); + await writeRunnerStdout(`${JSON.stringify(result, null, 2)}\n`); + process.exit(0); } catch (error) { if (error.failureClass) { - writeRunnerStderr(`[plugin-inspector:${error.failureClass}]\n`); + await writeRunnerStderr(`[plugin-inspector:${error.failureClass}]\n`); } - writeRunnerStderr(`${error.stack ?? error.message}\n`); - process.exitCode = 1; + await writeRunnerStderr(`${error.stack ?? error.message}\n`); + process.exit(1); } async function run(options) { @@ -162,9 +164,11 @@ async function drainAsyncOutput() { } function writeRunnerStdout(text) { - (activeOutputCapture?.originalStdoutWrite ?? process.stdout.write.bind(process.stdout))(text); + const write = activeOutputCapture?.originalStdoutWrite ?? process.stdout.write.bind(process.stdout); + return flushWrite(write, text); } function writeRunnerStderr(text) { - (activeOutputCapture?.originalStderrWrite ?? process.stderr.write.bind(process.stderr))(text); + const write = activeOutputCapture?.originalStderrWrite ?? process.stderr.write.bind(process.stderr); + return flushWrite(write, text); } diff --git a/src/process-profile.js b/src/process-profile.js index fb9b11f..12d382e 100644 --- a/src/process-profile.js +++ b/src/process-profile.js @@ -1,6 +1,9 @@ import { spawn } from "node:child_process"; import { performance } from "node:perf_hooks"; +export const defaultProfileTimeoutMs = 30_000; +export const defaultProfileMaxOutputBytes = 1024 * 1024; + export async function runProfiledProcess(options) { const start = performance.now(); const heapStartMb = heapUsedMb(); @@ -13,14 +16,20 @@ export async function runProfiledProcess(options) { const cpuSamples = []; let pollInFlight = false; const pendingStats = new Set(); + const timeoutMs = resolveProfileTimeoutMs(options); + const maxOutputBytes = resolveProfileMaxOutputBytes(options); + let timedOut = false; + let poll; + let timeoutId; + let forceKillId; const child = spawn(options.command, options.args ?? [], { cwd: options.cwd, env: options.env, stdio: options.stdio ?? ["ignore", "pipe", "pipe"], }); - const stdout = []; - const stderr = []; + const stdout = createCappedCollector(maxOutputBytes); + const stderr = createCappedCollector(maxOutputBytes); child.stdout?.on("data", (chunk) => stdout.push(chunk)); child.stderr?.on("data", (chunk) => stderr.push(chunk)); @@ -60,45 +69,117 @@ export async function runProfiledProcess(options) { pendingStats.add(pending); }; + const stopWatching = () => { + if (poll !== undefined) { + clearInterval(poll); + poll = undefined; + } + if (timeoutId !== undefined) { + clearTimeout(timeoutId); + timeoutId = undefined; + } + if (forceKillId !== undefined) { + clearTimeout(forceKillId); + forceKillId = undefined; + } + }; + sampleStats(); - const poll = setInterval(sampleStats, options.pollMs ?? 25); + poll = setInterval(sampleStats, options.pollMs ?? 25); - const exitCode = await new Promise((resolve, reject) => { - child.on("error", (error) => { - clearInterval(poll); - reject(error); + try { + const exitCode = await new Promise((resolve, reject) => { + let settled = false; + const finish = (fn) => { + if (settled) { + return; + } + settled = true; + stopWatching(); + fn(); + }; + child.on("error", (error) => finish(() => reject(error))); + child.on("exit", (code) => finish(() => resolve(code ?? 1))); + if (timeoutMs > 0) { + timeoutId = setTimeout(() => { + timedOut = true; + child.kill("SIGTERM"); + forceKillId = setTimeout(() => { + if (child.exitCode === null && child.signalCode === null) { + child.kill("SIGKILL"); + } + }, options.killGraceMs ?? 1000); + }, timeoutMs); + } }); - child.on("exit", (code) => resolve(code ?? 1)); - }); - clearInterval(poll); - await Promise.allSettled([...pendingStats]); - - const finalStats = await readProcessStats(child.pid); - recordStats(finalStats); - - const wallMs = Math.round(performance.now() - start); - const averageCpuPercent = - cpuSamples.length > 0 - ? cpuSamples.reduce((sum, value) => sum + value, 0) / cpuSamples.length - : 0; - const cpuPercentForEstimate = - options.roundAverageCpuPercent === true - ? Math.round(averageCpuPercent * 10) / 10 - : averageCpuPercent; + await Promise.allSettled([...pendingStats]); + + const finalStats = await readProcessStats(child.pid); + recordStats(finalStats); + + const wallMs = Math.round(performance.now() - start); + const averageCpuPercent = + cpuSamples.length > 0 + ? cpuSamples.reduce((sum, value) => sum + value, 0) / cpuSamples.length + : 0; + const cpuPercentForEstimate = + options.roundAverageCpuPercent === true + ? Math.round(averageCpuPercent * 10) / 10 + : averageCpuPercent; + + return { + wallMs, + peakRssMb: Math.round((peakRssKb / 1024) * 10) / 10, + rssDeltaMb: Math.round(((peakRssKb - firstRssKb) / 1024) * 10) / 10, + peakCpuPercent: Math.round(peakCpuPercent * 10) / 10, + cpuMsEstimate: Math.round((wallMs * cpuPercentForEstimate) / 100), + harnessHeapDeltaMb: Math.round((heapUsedMb() - heapStartMb) * 10) / 10, + statSampleCount, + rssSampleCount, + cpuSampleCount, + exitCode, + timedOut, + pid: child.pid, + stdoutPreview: previewLines(stdout.chunks), + stderrPreview: previewLines(stderr.chunks), + }; + } finally { + stopWatching(); + } +} + +export function resolveProfileTimeoutMs(options = {}) { + if (Number.isFinite(options.timeoutMs) && options.timeoutMs >= 0) { + return options.timeoutMs; + } + const fromEnv = Number.parseInt(String(options.env?.PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS ?? process.env.PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS ?? ""), 10); + if (Number.isFinite(fromEnv) && fromEnv >= 0) { + return fromEnv; + } + return defaultProfileTimeoutMs; +} + +export function resolveProfileMaxOutputBytes(options = {}) { + if (Number.isFinite(options.maxOutputBytes) && options.maxOutputBytes >= 0) { + return options.maxOutputBytes; + } + return defaultProfileMaxOutputBytes; +} +function createCappedCollector(maxBytes) { + const chunks = []; + let size = 0; return { - wallMs, - peakRssMb: Math.round((peakRssKb / 1024) * 10) / 10, - rssDeltaMb: Math.round(((peakRssKb - firstRssKb) / 1024) * 10) / 10, - peakCpuPercent: Math.round(peakCpuPercent * 10) / 10, - cpuMsEstimate: Math.round((wallMs * cpuPercentForEstimate) / 100), - harnessHeapDeltaMb: Math.round((heapUsedMb() - heapStartMb) * 10) / 10, - statSampleCount, - rssSampleCount, - cpuSampleCount, - exitCode, - stdoutPreview: previewLines(stdout), - stderrPreview: previewLines(stderr), + chunks, + push(chunk) { + if (size >= maxBytes) { + return; + } + const buffer = Buffer.isBuffer(chunk) ? chunk : Buffer.from(chunk); + const room = maxBytes - size; + chunks.push(buffer.length > room ? buffer.subarray(0, room) : buffer); + size += Math.min(buffer.length, room); + }, }; } diff --git a/src/runtime-profile.js b/src/runtime-profile.js index 1030af7..d8f4df8 100644 --- a/src/runtime-profile.js +++ b/src/runtime-profile.js @@ -333,6 +333,9 @@ async function profileCommand(command, options) { env: { ...process.env, ...options.env, ...command.env }, stdio: ["ignore", "pipe", "pipe"], roundAverageCpuPercent: true, + timeoutMs: command.timeoutMs ?? options.timeoutMs, + maxOutputBytes: command.maxOutputBytes ?? options.maxOutputBytes, + killGraceMs: command.killGraceMs ?? options.killGraceMs, }); } diff --git a/test/capture-timeout.test.js b/test/capture-timeout.test.js new file mode 100644 index 0000000..676f706 --- /dev/null +++ b/test/capture-timeout.test.js @@ -0,0 +1,172 @@ +import assert from "node:assert/strict"; +import { execFile } from "node:child_process"; +import { mkdtemp, writeFile } from "node:fs/promises"; +import os from "node:os"; +import path from "node:path"; +import { promisify } from "node:util"; +import { test } from "node:test"; +import { captureEntrypoint, classifyMockSdkCaptureError } from "../src/inspector.js"; + +const execFileAsync = promisify(execFile); + +async function writeHangingRegisterPlugin(dir) { + const entrypoint = path.join(dir, "index.mjs"); + await writeFile( + entrypoint, + [ + "export default {", + " async register() {", + " await new Promise(() => {", + " setInterval(() => {}, 1000);", + " });", + " }", + "};", + "", + ].join("\n"), + "utf8", + ); + return "index.mjs"; +} + +test("default mock-SDK capture timeout is a documented 30s budget", async () => { + const { defaultCaptureTimeoutMs } = await import("../src/inspector.js"); + assert.equal(defaultCaptureTimeoutMs, 30_000); +}); + +test("classifyMockSdkCaptureError treats a killed child as a capture timeout", () => { + const error = Object.assign(new Error("Command failed: node mock-sdk-capture-runner.js"), { + killed: true, + signal: "SIGTERM", + code: null, + stdout: "", + stderr: "", + }); + + const classified = classifyMockSdkCaptureError(error); + + assert.equal(classified.failureClass, "capture-timeout"); + assert.match(classified.message, /timed out/i); +}); + +test( + "mock capture escalates to SIGKILL when register() ignores SIGTERM", + { timeout: 2500 }, + async () => { + const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-sigterm-")); + const entrypoint = path.join(dir, "index.mjs"); + await writeFile( + entrypoint, + [ + "export default {", + " async register() {", + " process.on('SIGTERM', () => {});", + " await new Promise(() => {", + " setInterval(() => {}, 1000);", + " });", + " },", + "};", + "", + ].join("\n"), + "utf8", + ); + + await assert.rejects( + () => + captureEntrypoint(entrypoint, { + cwd: dir, + pluginRoot: dir, + mockSdk: true, + timeoutMs: 200, + killGraceMs: 50, + }), + (error) => { + assert.equal(error.failureClass, "capture-timeout"); + assert.match(error.message, /timed out/i); + return true; + }, + ); + }, +); + +test( + "mock capture fails closed when register() never settles", + { timeout: 2500 }, + async () => { + const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-hang-")); + const entrypoint = await writeHangingRegisterPlugin(dir); + + await assert.rejects( + () => + captureEntrypoint(entrypoint, { + cwd: dir, + pluginRoot: dir, + mockSdk: true, + timeoutMs: 200, + }), + (error) => { + assert.equal(error.failureClass, "capture-timeout"); + assert.match(error.message, /timed out/i); + return true; + }, + ); + }, +); + +test( + "plugin-inspector capture --allow-execute prints complete JSON on the CLI pipe", + { timeout: 4000 }, + async () => { + const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-cli-ok-")); + const entrypoint = path.join(dir, "index.mjs"); + await writeFile( + entrypoint, + [ + "export default {", + " register() {", + " return undefined;", + " },", + "};", + "", + ].join("\n"), + "utf8", + ); + const cliPath = path.resolve("src/cli.js"); + + const { stdout } = await execFileAsync( + process.execPath, + [cliPath, "capture", "index.mjs", "--allow-execute", "--mock-sdk"], + { cwd: dir }, + ); + + const parsed = JSON.parse(stdout); + assert.equal(parsed.status, "captured"); + assert.equal(parsed.mockSdk, true); + assert.ok(Array.isArray(parsed.captured)); + }, +); + +test( + "plugin-inspector capture --allow-execute times out a register() that never settles", + { timeout: 4000 }, + async () => { + const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-cli-hang-")); + const entrypoint = await writeHangingRegisterPlugin(dir); + const cliPath = path.resolve("src/cli.js"); + + await assert.rejects( + () => + execFileAsync(process.execPath, [cliPath, "capture", entrypoint, "--allow-execute", "--mock-sdk"], { + cwd: dir, + env: { + ...process.env, + PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS: "200", + }, + timeout: 3000, + }), + (error) => { + assert.match(String(error.stderr ?? error.message), /timed out|capture-timeout/i); + return true; + }, + ); + }, +); diff --git a/test/flush-write.test.js b/test/flush-write.test.js new file mode 100644 index 0000000..a7ac44c --- /dev/null +++ b/test/flush-write.test.js @@ -0,0 +1,32 @@ +import assert from "node:assert/strict"; +import { test } from "node:test"; +import { flushWrite } from "../src/flush-write.js"; + +test("flushWrite does not resolve until the write callback runs", async () => { + let callback; + const write = (_chunk, cb) => { + callback = cb; + return false; + }; + let settled = false; + const pending = flushWrite(write, '{"status":"captured"}\n').then(() => { + settled = true; + }); + + await Promise.resolve(); + assert.equal(settled, false); + callback(); + await pending; + assert.equal(settled, true); +}); + +test("flushWrite rejects when the write callback reports an error", async () => { + await assert.rejects( + () => + flushWrite((_chunk, cb) => { + cb(new Error("EPIPE")); + return false; + }, "x\n"), + /EPIPE/, + ); +}); diff --git a/test/process-profile.test.js b/test/process-profile.test.js new file mode 100644 index 0000000..682d6e7 --- /dev/null +++ b/test/process-profile.test.js @@ -0,0 +1,122 @@ +import assert from "node:assert/strict"; +import { mkdtemp, writeFile } from "node:fs/promises"; +import os from "node:os"; +import path from "node:path"; +import { test } from "node:test"; +import { buildImportLoopProfile } from "../src/import-loop-profile.js"; +import { runProfiledProcess } from "../src/process-profile.js"; +import { buildRuntimeProfile } from "../src/runtime-profile.js"; + +function processExists(pid) { + if (!pid) { + return false; + } + try { + process.kill(pid, 0); + return true; + } catch { + return false; + } +} + +test("default profile timeout and output caps are documented", async () => { + const { defaultProfileMaxOutputBytes, defaultProfileTimeoutMs } = await import("../src/process-profile.js"); + assert.equal(defaultProfileTimeoutMs, 30_000); + assert.equal(defaultProfileMaxOutputBytes, 1024 * 1024); +}); + +test("profiled process that never exits is killed when the timeout expires", { timeout: 2500 }, async () => { + const result = await runProfiledProcess({ + command: process.execPath, + args: ["-e", "setInterval(() => {}, 1000)"], + timeoutMs: 200, + pollMs: 25, + }); + + assert.equal(result.timedOut, true); + assert.notEqual(result.exitCode, 0); + assert.ok(result.wallMs >= 150); + assert.ok(result.wallMs < 1500); + assert.equal(processExists(result.pid), false); +}); + +test("profiled process caps stdout and stderr and still returns", { timeout: 2500 }, async () => { + const result = await runProfiledProcess({ + command: process.execPath, + args: [ + "-e", + "process.stdout.write('x'.repeat(20000) + '\\nstdout-tail\\n'); process.stderr.write('y'.repeat(20000) + '\\nstderr-tail\\n');", + ], + timeoutMs: 2000, + maxOutputBytes: 64, + }); + + assert.equal(result.exitCode, 0); + assert.ok(Buffer.byteLength(result.stdoutPreview) <= 64); + assert.ok(Buffer.byteLength(result.stderrPreview) <= 64); +}); + +test( + "buildRuntimeProfile times out a command that never exits", + { timeout: 4000 }, + async () => { + const profile = await buildRuntimeProfile({ + commands: [ + { + id: "hang", + label: "Hang", + category: "baseline", + args: ["-e", "setInterval(() => {}, 1000)"], + }, + ], + generatedAt: "test", + runs: 1, + timeoutMs: 200, + }); + + const hang = profile.commands.find((command) => command.id === "hang"); + assert.ok(hang); + assert.ok(hang.exitCodes.some((code) => code !== 0)); + assert.ok(hang.samples.every((sample) => sample.timedOut === true)); + assert.ok(hang.wallMs.max < 2000); + }, +); + +test( + "buildImportLoopProfile times out a capture subprocess that never exits", + { timeout: 4000 }, + async () => { + const rootDir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-import-loop-hang-")); + const hangScript = path.join(rootDir, "hang.mjs"); + const entrypoint = path.join(rootDir, "fixture.mjs"); + await writeFile(hangScript, "setInterval(() => {}, 1000);\n", "utf8"); + await writeFile( + entrypoint, + [ + "export default {", + " register(api) {", + " api.registerTool({ name: 'fixture_tool', inputSchema: { type: 'object' }, run() {} });", + " }", + "};", + "", + ].join("\n"), + "utf8", + ); + + const profile = await buildImportLoopProfile({ + baseline: false, + captureCommand: () => ({ + command: process.execPath, + args: [hangScript], + }), + entrypoint, + rootDir, + runs: 1, + timeoutMs: 200, + }); + + assert.ok(profile.summary.failCount > 0); + assert.ok(profile.samples.every((sample) => sample.timedOut === true)); + assert.ok(profile.samples.every((sample) => sample.wallMs < 2000)); + }, +); From e8e81a4b6d12e82dd2f460408d8af9abcd60ed8b Mon Sep 17 00:00:00 2001 From: Vincent Koc Date: Wed, 9 Sep 2026 15:19:02 +0000 Subject: [PATCH 2/2] fix: supervise owned capture and profile process lifecycles --- CHANGELOG.md | 5 + README.md | 52 +++- src/flush-write.js | 21 -- src/import-loop-profile.js | 78 +++++- src/inspector.js | 191 +++----------- src/mock-sdk-capture-runner.js | 36 ++- src/process-profile.js | 393 ++++++++++++++++------------ src/runtime-profile.js | 1 + test/capture-timeout.test.js | 353 ++++++++++++++----------- test/flush-write.test.js | 32 --- test/process-profile.test.js | 460 +++++++++++++++++++++++++++------ 11 files changed, 979 insertions(+), 643 deletions(-) delete mode 100644 src/flush-write.js delete mode 100644 test/flush-write.test.js diff --git a/CHANGELOG.md b/CHANGELOG.md index d9217f9..13eddd1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,11 @@ ## Unreleased +### Fixed + +- Bound mock-SDK capture and profile child lifetimes, output, and process sampling; clean owned POSIX descendants through stdio close and keep timeout/cancellation outcomes unsuccessful. Flush complete capture JSON before exiting despite retained plugin timers. Thanks @SebTardif. +- Profile the default import-loop capture runner directly so its timeout also owns plugin execution. Validate fresh, bounded capture artifacts; RSS/CPU and wall-time measurements now exclude the intermediate CLI wrapper and are not directly comparable with historical profiles. + ## 0.3.24 - 2026-08-31 ### Fixed diff --git a/README.md b/README.md index 5ee0bf1..ba98eb2 100644 --- a/README.md +++ b/README.md @@ -250,16 +250,48 @@ Capture one entrypoint directly: plugin-inspector capture ./dist/index.js --mock-sdk --allow-execute ``` -Mock-SDK capture runs the plugin in a child process. If `register()` never -settles, or the child never exits, the inspector kills that child after 30 -seconds and reports a `capture-timeout` failure instead of hanging. Override -the budget with `timeoutMs` or `PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS`. - -Import-loop and runtime profiles use the same 30-second child budget so a -command that never exits cannot stall `buildImportLoopProfile` or -`buildRuntimeProfile`. Override those with `timeoutMs` or -`PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS`. Profiled stdout and stderr are capped -at 1 MB. +Mock-SDK capture and import-loop/runtime profiles give each child a 30-second +budget. Mock capture reports `capture-timeout`; timed-out profile samples +always have a nonzero `exitCode`, even if a SIGTERM handler exits zero. +Pass an `AbortSignal` as `signal` to cancel owned-child work. Cancellation is +never a successful capture or profile sample. + +On POSIX, each child owns a separate process group. Completion waits for +stdout/stderr to close and cleans descendants, including after a successful +leader exit. Shutdown sends SIGTERM, then SIGKILL after a 1-second grace +period. A further 1-second close deadline fails the operation if pipes remain +open. Descendants that deliberately leave the group are not contained; +this is lifecycle supervision, not a sandbox. Windows retains direct-child +termination and the bounded close deadline, not POSIX group cleanup. + +The API options `timeoutMs`, `killGraceMs`, and `maxOutputBytes` take precedence +over `PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS`, `PLUGIN_INSPECTOR_CAPTURE_KILL_GRACE_MS`, +and `PLUGIN_INSPECTOR_CAPTURE_MAX_OUTPUT_BYTES` for mock capture. Profiles use +the corresponding `PLUGIN_INSPECTOR_PROFILE_*` variables. Values must be finite +positive numbers (zero does not disable limits); invalid values fall through +to the environment, then defaults. Durations/byte limits cannot exceed +2,147,483,647; grace cannot exceed 30,000 ms. + +Each profiled stdout/stderr stream retains at most 1 MiB by default while +continuing to drain output. Mock capture retains at most 10 MiB per pipe and +fails if its JSON response is truncated; intercepted plugin stdout/stderr +inside that response retains at most 1 MiB each. The optional `ps` sampler +also has bounded output, execution, and cleanup. + +Default import-loop profiles launch the mock capture runner directly under one +profile budget, for both baseline and plugin samples. Their JSON artifacts +retain capture's 10 MiB default limit (`PLUGIN_INSPECTOR_CAPTURE_MAX_OUTPUT_BYTES`, +or an explicit `maxOutputBytes` override), separately from the profile's +1 MiB stdout/stderr limits. Artifacts are accepted only after a successful +current capture. RSS and CPU now measure the actual runner, and wall time no +longer includes intermediate CLI startup. Historical measurements from the +CLI-wrapper route are not directly comparable. Custom `captureCommand` and +`captureScript` launch contracts are unchanged; custom detached groups are +outside the owned process group. + +These limits apply to owned child processes only. The public in-process +`captureEntrypoint` path preserves retained handler identity and does not +claim to cancel synchronous plugin code or retained callbacks. ## CI diff --git a/src/flush-write.js b/src/flush-write.js deleted file mode 100644 index a3525b7..0000000 --- a/src/flush-write.js +++ /dev/null @@ -1,21 +0,0 @@ -export function flushWrite(write, text) { - return new Promise((resolve, reject) => { - let settled = false; - const done = (err) => { - if (settled) { - return; - } - settled = true; - if (err) { - reject(err); - return; - } - resolve(); - }; - try { - write(text, done); - } catch (err) { - done(err); - } - }); -} diff --git a/src/import-loop-profile.js b/src/import-loop-profile.js index 821aa04..74f640c 100644 --- a/src/import-loop-profile.js +++ b/src/import-loop-profile.js @@ -1,12 +1,13 @@ -import { mkdir, writeFile } from "node:fs/promises"; +import { constants } from "node:fs"; +import { mkdir, open, readFile, rm, writeFile } from "node:fs/promises"; import path from "node:path"; import { fileURLToPath } from "node:url"; import { renderPaddedMarkdownTable, writeJsonMarkdownArtifacts } from "./artifacts.js"; import { resolveFromRoot } from "./path-utils.js"; -import { runProfiledProcess } from "./process-profile.js"; +import { resolveProcessLimits, runProfiledProcess } from "./process-profile.js"; import { assertRunCount, percentile } from "./stats.js"; -const defaultCliPath = fileURLToPath(new URL("./cli.js", import.meta.url)); +const defaultRunnerPath = fileURLToPath(new URL("./mock-sdk-capture-runner.js", import.meta.url)); export const defaultImportLoopProfileOptions = { entrypoint: "test/fixtures/lazy-import-plugin.mjs", @@ -255,22 +256,49 @@ async function runCaptureSample(options) { const outputPath = path.join(outputDir, `${options.sampleName ?? "capture"}-${options.index}.json`); await mkdir(path.dirname(outputPath), { recursive: true }); - const command = buildCaptureCommand({ ...options, outputPath }); + const defaultCapture = typeof options.captureCommand !== "function" && !options.captureScript; + const maxOutputBytes = resolveProcessLimits({ + ...options, + env: { ...process.env, ...options.env, ...options.captureEnv }, + }, "CAPTURE").maxOutputBytes; + // Only the built-in route owns these sample files. An early process.exit(0) + // must not turn a previous capture into this run's successful result. + if (defaultCapture) await rm(outputPath, { force: true }); + const command = buildCaptureCommand({ ...options, outputPath, maxOutputBytes }); const profile = await runProfiledProcess({ command: command.command, args: command.args, cwd: command.cwd ?? options.rootDir, - env: { ...process.env, ...command.env }, + env: { ...process.env, ...options.env, ...command.env }, timeoutMs: options.timeoutMs, maxOutputBytes: options.maxOutputBytes, killGraceMs: options.killGraceMs, + signal: options.signal, }); - const output = profile.exitCode === 0 ? await readCaptureOutput(outputPath) : null; + let output = null; + if (profile.exitCode === 0 && !profile.timedOut && !profile.cancelled) { + if (defaultCapture) { + try { + output = await readCaptureOutput(outputPath, maxOutputBytes); + } catch (error) { + profile.exitCode = 1; + profile.stderrPreview = `Invalid capture artifact: ${error.message}`; + } + } else { + output = await readCaptureOutput(outputPath); + } + } + if (options.signal?.aborted) { + profile.exitCode = 1; + profile.cancelled = true; + output = null; + } return { index: options.index, exitCode: profile.exitCode, timedOut: profile.timedOut === true, + cancelled: profile.cancelled === true, status: output?.status ?? "failed", capturedCount: output?.captured?.length ?? 0, openClawLifecycle: output?.openClawLifecycle ?? null, @@ -411,15 +439,45 @@ function buildCaptureCommand(options) { } return { command: process.execPath, - args: [defaultCliPath, "capture", options.entrypoint, "--output", options.outputPath], + args: [ + "--no-warnings", + "--preserve-symlinks", + defaultRunnerPath, + JSON.stringify({ + entrypoint: options.entrypoint, + cwd: options.rootDir, + outputPath: options.outputPath, + maxOutputBytes: options.maxOutputBytes, + }), + ], cwd: options.rootDir, env: { PLUGIN_INSPECTOR_EXECUTE_ISOLATED: "1", ...options.captureEnv }, }; } -async function readCaptureOutput(outputPath) { - const { readFile } = await import("node:fs/promises"); - return JSON.parse(await readFile(outputPath, "utf8")); +async function readCaptureOutput(outputPath, maxOutputBytes) { + if (maxOutputBytes === undefined) return JSON.parse(await readFile(outputPath, "utf8")); + const file = await open(outputPath, constants.O_RDONLY | constants.O_NONBLOCK); + try { + const stat = await file.stat(); + if (!stat.isFile()) throw new Error("expected a regular capture file"); + if (stat.size > maxOutputBytes) throw new Error("capture result exceeded its byte limit"); + const chunks = []; + let bytes = 0; + // end is inclusive: read at most limit + 1 even if the file grew after stat. + for await (const chunk of file.createReadStream({ end: maxOutputBytes, autoClose: false })) { + chunks.push(chunk); + bytes += chunk.length; + } + if (bytes > maxOutputBytes) throw new Error("capture result exceeded its byte limit"); + const result = JSON.parse(Buffer.concat(chunks, bytes).toString("utf8")); + if (!result || typeof result.status !== "string" || !Array.isArray(result.captured)) { + throw new Error("expected a capture status and captured contracts"); + } + return result; + } finally { + await file.close(); + } } function markdownTable(rows, headers) { diff --git a/src/inspector.js b/src/inspector.js index 3a85fb1..a058cb4 100644 --- a/src/inspector.js +++ b/src/inspector.js @@ -1,5 +1,4 @@ import { existsSync } from "node:fs"; -import { spawn } from "node:child_process"; import { readdir, readFile } from "node:fs/promises"; import * as nodeModule from "node:module"; import path from "node:path"; @@ -10,14 +9,13 @@ import { fixtureCheckoutPath, fixtureSourceRoot } from "./config.js"; import { buildCompatibilityFixtureReport } from "./fixture-summary.js"; import { readOpenClawTargetSurface } from "./openclaw-target.js"; import { prepareOpenClawTarget, resolveOpenClawTargetVersion } from "./openclaw-version.js"; +import { startOwnedProcess } from "./process-profile.js"; import { buildCompatibilityReport, buildReport } from "./report.js"; import { inspectSdkDeprecations } from "./sdk-deprecation-rules.js"; const pluginFactoryNames = "defineBundledChannelEntry|defineChannelPluginEntry|createChatChannelPlugin|definePluginEntry"; // Bundlers emit unbound calls as (0, sdk.factory)(...), including inline require receivers. const compiledFactoryCall = new RegExp(String.raw`\(\s*0\s*,\s*(?:require\s*\(\s*(?:"[^"\r\n]*"|'[^'\r\n]*')\s*\)|[$A-Z_a-z][$\w]*)(?:\s*\.\s*[$A-Z_a-z][$\w]*)*\s*\.\s*(${pluginFactoryNames})\s*\)\s*\(`, "dg"); -export const defaultCaptureTimeoutMs = 30_000; -export const defaultCaptureKillGraceMs = 1_000; const registrationEquivalents = new Map([ ["registerChannel", new Set(["createChatChannelPlugin", "defineBundledChannelEntry", "defineChannelPluginEntry", "registerChannel"])], ]); @@ -232,177 +230,46 @@ export async function captureEntrypointWithMockSdk(entrypoint, options = {}) { cwd: options.cwd ?? process.cwd(), pluginRoot: options.pluginRoot, apiOptions: options.apiOptions, + maxOutputBytes: options.maxOutputBytes, }; - const timeoutMs = resolveCaptureTimeoutMs(options); - const killGraceMs = resolveCaptureKillGraceMs(options); + const { result } = startOwnedProcess({ + command: process.execPath, + args: ["--no-warnings", "--preserve-symlinks", runnerPath, JSON.stringify(payload)], + cwd: options.cwd ?? process.cwd(), + env: { ...process.env, ...options.env }, + timeoutMs: options.timeoutMs, + killGraceMs: options.killGraceMs, + maxOutputBytes: options.maxOutputBytes, + signal: options.signal, + }, "CAPTURE"); + const outcome = await result; + if (outcome.exitCode !== 0 || outcome.outputTruncated) { + const message = outcome.cancelled ? "Mock SDK capture cancelled" + : outcome.outputTruncated ? "Mock SDK capture output exceeded its byte limit" + : "Mock SDK capture child failed"; + const { error: childError, ...details } = outcome; + throw classifyMockSdkCaptureError(Object.assign(childError ?? new Error(message), details)); + } try { - const { stdout } = await runMockSdkCaptureChild({ - runnerPath, - payload, - cwd: options.cwd ?? process.cwd(), - env: { - ...process.env, - ...(options.env ?? {}), - }, - timeoutMs, - killGraceMs, - maxBuffer: 1024 * 1024 * 10, - }); - return JSON.parse(stdout); + return JSON.parse(outcome.stdout); } catch (error) { - error.timeoutMs = timeoutMs; - const captured = parseCaptureResultFromStdout(error?.stdout); - if (captured && !isChildTimeoutError(error)) { - return captured; - } throw classifyMockSdkCaptureError(error); } } -export function resolveCaptureTimeoutMs(options = {}) { - if (Number.isFinite(options.timeoutMs) && options.timeoutMs > 0) { - return options.timeoutMs; - } - const fromEnv = Number.parseInt(String(options.env?.PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS ?? process.env.PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS ?? ""), 10); - if (Number.isFinite(fromEnv) && fromEnv > 0) { - return fromEnv; - } - return defaultCaptureTimeoutMs; -} - -export function resolveCaptureKillGraceMs(options = {}) { - if (Number.isFinite(options.killGraceMs) && options.killGraceMs >= 0) { - return options.killGraceMs; - } - const fromEnv = Number.parseInt( - String(options.env?.PLUGIN_INSPECTOR_CAPTURE_KILL_GRACE_MS ?? process.env.PLUGIN_INSPECTOR_CAPTURE_KILL_GRACE_MS ?? ""), - 10, - ); - if (Number.isFinite(fromEnv) && fromEnv >= 0) { - return fromEnv; - } - return defaultCaptureKillGraceMs; -} - -function runMockSdkCaptureChild({ runnerPath, payload, cwd, env, timeoutMs, killGraceMs, maxBuffer }) { - return new Promise((resolve, reject) => { - const child = spawn( - process.execPath, - ["--no-warnings", "--preserve-symlinks", runnerPath, JSON.stringify(payload)], - { cwd, env, stdio: ["ignore", "pipe", "pipe"] }, - ); - const stdoutChunks = []; - const stderrChunks = []; - let stdoutBytes = 0; - let settled = false; - let timedOut = false; - let timeoutId; - let forceKillId; - - const finish = (err, result) => { - if (settled) { - return; - } - settled = true; - if (timeoutId !== undefined) { - clearTimeout(timeoutId); - } - if (forceKillId !== undefined) { - clearTimeout(forceKillId); - } - if (err) { - reject(err); - return; - } - resolve(result); - }; - - child.stdout?.on("data", (chunk) => { - stdoutBytes += chunk.length; - if (stdoutBytes <= maxBuffer) { - stdoutChunks.push(chunk); - } - }); - child.stderr?.on("data", (chunk) => { - stderrChunks.push(chunk); - }); - child.on("error", (error) => finish(error)); - child.on("exit", (code, signal) => { - const stdout = Buffer.concat(stdoutChunks).toString("utf8"); - const stderr = Buffer.concat(stderrChunks).toString("utf8"); - if (timedOut) { - finish( - Object.assign(new Error("Command failed: node mock-sdk-capture-runner.js"), { - killed: true, - signal: signal ?? "SIGKILL", - code, - stdout, - stderr, - }), - ); - return; - } - if (code === 0) { - finish(null, { stdout, stderr }); - return; - } - finish( - Object.assign(new Error("Command failed: node mock-sdk-capture-runner.js"), { - killed: false, - signal, - code, - stdout, - stderr, - }), - ); - }); - - if (timeoutMs > 0) { - timeoutId = setTimeout(() => { - timedOut = true; - child.kill("SIGTERM"); - forceKillId = setTimeout(() => { - if (child.exitCode === null && child.signalCode === null) { - child.kill("SIGKILL"); - } - }, killGraceMs); - }, timeoutMs); - } - }); -} - -export function isChildTimeoutError(error) { - return error?.killed === true && (error.signal === "SIGTERM" || error.signal === "SIGKILL"); -} - -function parseCaptureResultFromStdout(stdout) { - if (!stdout) { - return null; - } - try { - const parsed = JSON.parse(stdout); - if ( - parsed && - typeof parsed === "object" && - typeof parsed.status === "string" && - Array.isArray(parsed.captured) - ) { - return parsed; - } - } catch { - return null; - } - return null; -} - export function classifyMockSdkCaptureError(error) { - if (isChildTimeoutError(error)) { - const timeoutMs = Number.isFinite(error?.timeoutMs) ? error.timeoutMs : defaultCaptureTimeoutMs; + if (error?.timedOut === true) { return enrichCaptureError(error, { - message: `Mock SDK capture timed out after ${timeoutMs}ms`, + message: `Mock SDK capture timed out after ${error.timeoutMs}ms`, failureClass: "capture-timeout", }); } + if (error?.cancelled || error?.outputTruncated) { + return enrichCaptureError(error, { + message: error.message, + failureClass: "mock-sdk-capture-error", + }); + } const rawMessage = [error?.stderr, error?.stdout, error?.message].filter(Boolean).join("\n"); const missingExport = rawMessage.match(/does not provide an export named ['"]([^'"]+)['"]/)?.[1]; diff --git a/src/mock-sdk-capture-runner.js b/src/mock-sdk-capture-runner.js index 1607522..6a3ed97 100644 --- a/src/mock-sdk-capture-runner.js +++ b/src/mock-sdk-capture-runner.js @@ -5,9 +5,10 @@ import { register } from "node:module"; import os from "node:os"; import path from "node:path"; import { pathToFileURL } from "node:url"; +import { writeArtifacts } from "./artifacts.js"; import { createCaptureApi } from "./capture-api.js"; import { captureApiOptionsForPlugin } from "./capture-config.js"; -import { flushWrite } from "./flush-write.js"; +import { createCappedCollector, resolveProcessLimits } from "./process-profile.js"; import { createMockSdkPackage } from "./sdk-mock.js"; const options = JSON.parse(process.argv[2] ?? "{}"); @@ -15,13 +16,22 @@ let activeOutputCapture = null; try { const result = await run(options); - await writeRunnerStdout(`${JSON.stringify(result, null, 2)}\n`); + const json = `${JSON.stringify(result, null, 2)}\n`; + const { maxOutputBytes } = resolveProcessLimits(options, "CAPTURE"); + if (Buffer.byteLength(json) > maxOutputBytes) { + throw new Error(`Mock SDK capture result exceeded its ${maxOutputBytes}-byte limit`); + } + if (options.outputPath) { + await writeArtifacts([{ path: options.outputPath, content: json }]); + } else { + await writeRunnerStdout(json); + } process.exit(0); } catch (error) { if (error.failureClass) { await writeRunnerStderr(`[plugin-inspector:${error.failureClass}]\n`); } - await writeRunnerStderr(`${error.stack ?? error.message}\n`); + await writeRunnerStderr(`${options.outputPath ? error.message : (error.stack ?? error.message)}\n`); process.exit(1); } @@ -126,18 +136,18 @@ function findRegisterExport(module) { } function installProcessOutputCapture() { - const stdoutChunks = []; - const stderrChunks = []; + const stdout = createCappedCollector(1024 * 1024); + const stderr = createCappedCollector(1024 * 1024); const originalStdoutWrite = process.stdout.write.bind(process.stdout); const originalStderrWrite = process.stderr.write.bind(process.stderr); process.stdout.write = (chunk, encoding, callback) => { - stdoutChunks.push(Buffer.isBuffer(chunk) ? chunk.toString("utf8") : String(chunk)); + stdout.push(Buffer.isBuffer(chunk) ? chunk : Buffer.from(String(chunk), typeof encoding === "string" ? encoding : "utf8")); invokeWriteCallback(encoding, callback); return true; }; process.stderr.write = (chunk, encoding, callback) => { - stderrChunks.push(Buffer.isBuffer(chunk) ? chunk.toString("utf8") : String(chunk)); + stderr.push(Buffer.isBuffer(chunk) ? chunk : Buffer.from(String(chunk), typeof encoding === "string" ? encoding : "utf8")); invokeWriteCallback(encoding, callback); return true; }; @@ -145,8 +155,8 @@ function installProcessOutputCapture() { return { originalStdoutWrite, originalStderrWrite, - stdout: () => stdoutChunks.join(""), - stderr: () => stderrChunks.join(""), + stdout: () => stdout.text(), + stderr: () => stderr.text(), }; } @@ -172,3 +182,11 @@ function writeRunnerStderr(text) { const write = activeOutputCapture?.originalStderrWrite ?? process.stderr.write.bind(process.stderr); return flushWrite(write, text); } + +// The runner exits deliberately to shed plugin timers, but only after the +// complete protocol response has reached its pipe. +function flushWrite(write, text) { + return new Promise((resolve, reject) => { + write(text, (error) => error ? reject(error) : resolve()); + }); +} diff --git a/src/process-profile.js b/src/process-profile.js index 12d382e..8181396 100644 --- a/src/process-profile.js +++ b/src/process-profile.js @@ -1,8 +1,146 @@ import { spawn } from "node:child_process"; import { performance } from "node:perf_hooks"; -export const defaultProfileTimeoutMs = 30_000; -export const defaultProfileMaxOutputBytes = 1024 * 1024; +const defaultTimeoutMs = 30_000; +const defaultKillGraceMs = 1_000; +const maxTimerMs = 2 ** 31 - 1; +const killWaitMs = 1_000; + +// Shared by capture and profiling, not a package entrypoint. Each spawn owns +// its POSIX process group; never signal the inspector's inherited group. +export function startOwnedProcess(options, kind = "PROFILE") { + const env = options.env ?? process.env; + const { timeoutMs, killGraceMs, maxOutputBytes } = resolveProcessLimits(options, kind); + const stdout = createCappedCollector(maxOutputBytes); + const stderr = createCappedCollector(maxOutputBytes); + let timedOut = false; + let cancelled = options.signal?.aborted === true; + let error; + let closed = false; + let stopping = false; + let escalated = false; + let settled = false; + let code; + let exitSignal; + let timeoutId; + let forceKillId; + let closeDeadlineId; + let child; + let resolveResult; + const result = new Promise((resolve) => { resolveResult = resolve; }); + + const finish = () => { + if (settled) return; + settled = true; + clearTimeout(timeoutId); + clearTimeout(forceKillId); + clearTimeout(closeDeadlineId); + options.signal?.removeEventListener("abort", cancel); + resolveResult({ + exitCode: timedOut || cancelled || error ? 1 : (code ?? 1), + timedOut, + cancelled, + timeoutMs, + signal: exitSignal, + pid: child?.pid, + error, + stdout: stdout.text(), + stderr: stderr.text(), + outputTruncated: stdout.truncated || stderr.truncated, + }); + }; + const groupExists = () => { + if (!child?.pid) return false; + if (process.platform === "win32") return child.exitCode === null && child.signalCode === null; + try { + process.kill(-child.pid, 0); + return true; + } catch (cause) { + if (cause.code === "ESRCH") return false; + error ??= cause; + return true; + } + }; + const signalGroup = (signal) => { + if (!child?.pid) return; + try { + if (process.platform === "win32") child.kill(signal); + else process.kill(-child.pid, signal); + } catch (cause) { + if (cause.code !== "ESRCH") error ??= cause; + } + }; + const stop = () => { + if (stopping || settled) return; + stopping = true; + signalGroup("SIGTERM"); + forceKillId = setTimeout(() => { + // The leader may already be reaped while its descendants hold the pipes. + signalGroup("SIGKILL"); + escalated = true; + if (closed) { + finish(); + return; + } + closeDeadlineId = setTimeout(() => { + error ??= new Error("Owned child stdio did not close after SIGKILL"); + child?.stdout?.destroy(); + child?.stderr?.destroy(); + child?.stdin?.destroy(); + child?.unref(); + finish(); + }, killWaitMs); + }, killGraceMs); + }; + const cancel = () => { + cancelled = true; + stop(); + }; + + if (cancelled) { + finish(); + return { child, result }; + } + try { + child = spawn(options.command, options.args ?? [], { + cwd: options.cwd, + env, + detached: process.platform !== "win32", + stdio: options.stdio ?? ["ignore", "pipe", "pipe"], + }); + } catch (cause) { + error = cause; + finish(); + return { child, result }; + } + child.stdout?.on("data", (chunk) => stdout.push(chunk)); + child.stderr?.on("data", (chunk) => stderr.push(chunk)); + const fail = (cause) => { + error ??= cause; + stop(); + }; + child.stdout?.on("error", fail); + child.stderr?.on("error", fail); + child.once("error", fail); + child.once("exit", () => { + // Clean descendants even after a successful leader exit or closed pipes. + if (groupExists()) stop(); + }); + child.once("close", (exitCode, signal) => { + closed = true; + code = exitCode; + exitSignal = signal; + if (!escalated && groupExists()) stop(); + else finish(); + }); + timeoutId = setTimeout(() => { + timedOut = true; + stop(); + }, timeoutMs); + options.signal?.addEventListener("abort", cancel, { once: true }); + if (options.signal?.aborted) cancel(); + return { child, result }; +} export async function runProfiledProcess(options) { const start = performance.now(); @@ -13,120 +151,50 @@ export async function runProfiledProcess(options) { let statSampleCount = 0; let rssSampleCount = 0; let cpuSampleCount = 0; - const cpuSamples = []; - let pollInFlight = false; - const pendingStats = new Set(); - const timeoutMs = resolveProfileTimeoutMs(options); - const maxOutputBytes = resolveProfileMaxOutputBytes(options); - let timedOut = false; - let poll; - let timeoutId; - let forceKillId; - - const child = spawn(options.command, options.args ?? [], { - cwd: options.cwd, - env: options.env, - stdio: options.stdio ?? ["ignore", "pipe", "pipe"], - }); - const stdout = createCappedCollector(maxOutputBytes); - const stderr = createCappedCollector(maxOutputBytes); - child.stdout?.on("data", (chunk) => stdout.push(chunk)); - child.stderr?.on("data", (chunk) => stderr.push(chunk)); - - const recordStats = (stats) => { - if (stats.rssAvailable || stats.cpuAvailable) { - statSampleCount += 1; - } - if (stats.rssAvailable) { - rssSampleCount += 1; - } - if (stats.cpuAvailable) { - cpuSampleCount += 1; - } - if (stats.rssAvailable && stats.rssKb > 0 && firstRssKb === 0) { - firstRssKb = stats.rssKb; - } - if (stats.rssAvailable) { - peakRssKb = Math.max(peakRssKb, stats.rssKb); - } - if (stats.cpuAvailable) { - peakCpuPercent = Math.max(peakCpuPercent, stats.cpuPercent); - cpuSamples.push(stats.cpuPercent); - } - }; - + let cpuTotal = 0; + let pendingStats; + let stopped = false; + const statsController = new AbortController(); + const running = startOwnedProcess(options); const sampleStats = () => { - if (pollInFlight) { - return; - } - pollInFlight = true; - const pending = readProcessStats(child.pid) - .then(recordStats) - .finally(() => { - pollInFlight = false; - pendingStats.delete(pending); - }); - pendingStats.add(pending); + if (pendingStats || stopped || !running.child?.pid) return; + pendingStats = readProcessStats(running.child.pid, options.env, statsController.signal) + .then((stats) => { + if (stopped) return; + if (stats.rssAvailable || stats.cpuAvailable) statSampleCount += 1; + if (stats.rssAvailable) { + rssSampleCount += 1; + if (stats.rssKb > 0 && firstRssKb === 0) firstRssKb = stats.rssKb; + peakRssKb = Math.max(peakRssKb, stats.rssKb); + } + if (stats.cpuAvailable) { + cpuSampleCount += 1; + peakCpuPercent = Math.max(peakCpuPercent, stats.cpuPercent); + cpuTotal += stats.cpuPercent; + } + }) + .finally(() => { pendingStats = undefined; }); }; - - const stopWatching = () => { - if (poll !== undefined) { - clearInterval(poll); - poll = undefined; - } - if (timeoutId !== undefined) { - clearTimeout(timeoutId); - timeoutId = undefined; - } - if (forceKillId !== undefined) { - clearTimeout(forceKillId); - forceKillId = undefined; - } + const poll = setInterval(sampleStats, positiveLimit(options.pollMs, undefined, 25)); + const stopSampling = () => { + stopped = true; + clearInterval(poll); + statsController.abort(); }; - + running.child?.once("exit", stopSampling); + running.child?.once("error", stopSampling); sampleStats(); - poll = setInterval(sampleStats, options.pollMs ?? 25); try { - const exitCode = await new Promise((resolve, reject) => { - let settled = false; - const finish = (fn) => { - if (settled) { - return; - } - settled = true; - stopWatching(); - fn(); - }; - child.on("error", (error) => finish(() => reject(error))); - child.on("exit", (code) => finish(() => resolve(code ?? 1))); - if (timeoutMs > 0) { - timeoutId = setTimeout(() => { - timedOut = true; - child.kill("SIGTERM"); - forceKillId = setTimeout(() => { - if (child.exitCode === null && child.signalCode === null) { - child.kill("SIGKILL"); - } - }, options.killGraceMs ?? 1000); - }, timeoutMs); - } - }); - await Promise.allSettled([...pendingStats]); - - const finalStats = await readProcessStats(child.pid); - recordStats(finalStats); - + const outcome = await running.result; + stopSampling(); + await pendingStats; + if (outcome.error) throw outcome.error; const wallMs = Math.round(performance.now() - start); - const averageCpuPercent = - cpuSamples.length > 0 - ? cpuSamples.reduce((sum, value) => sum + value, 0) / cpuSamples.length - : 0; - const cpuPercentForEstimate = - options.roundAverageCpuPercent === true - ? Math.round(averageCpuPercent * 10) / 10 - : averageCpuPercent; - + const averageCpuPercent = cpuSampleCount > 0 ? cpuTotal / cpuSampleCount : 0; + const cpuPercentForEstimate = options.roundAverageCpuPercent === true + ? Math.round(averageCpuPercent * 10) / 10 + : averageCpuPercent; return { wallMs, peakRssMb: Math.round((peakRssKb / 1024) * 10) / 10, @@ -137,83 +205,82 @@ export async function runProfiledProcess(options) { statSampleCount, rssSampleCount, cpuSampleCount, - exitCode, - timedOut, - pid: child.pid, - stdoutPreview: previewLines(stdout.chunks), - stderrPreview: previewLines(stderr.chunks), + exitCode: outcome.exitCode, + timedOut: outcome.timedOut, + cancelled: outcome.cancelled, + pid: outcome.pid, + stdoutPreview: previewLines(outcome.stdout), + stderrPreview: previewLines(outcome.stderr), }; } finally { - stopWatching(); + stopSampling(); } } -export function resolveProfileTimeoutMs(options = {}) { - if (Number.isFinite(options.timeoutMs) && options.timeoutMs >= 0) { - return options.timeoutMs; - } - const fromEnv = Number.parseInt(String(options.env?.PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS ?? process.env.PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS ?? ""), 10); - if (Number.isFinite(fromEnv) && fromEnv >= 0) { - return fromEnv; - } - return defaultProfileTimeoutMs; +export function resolveProcessLimits(options, kind = "PROFILE") { + const env = options.env ?? process.env; + const setting = (name) => env[`PLUGIN_INSPECTOR_${kind}_${name}`] ?? process.env[`PLUGIN_INSPECTOR_${kind}_${name}`]; + return { + timeoutMs: positiveLimit(options.timeoutMs, setting("TIMEOUT_MS"), defaultTimeoutMs), + killGraceMs: positiveLimit(options.killGraceMs, setting("KILL_GRACE_MS"), defaultKillGraceMs, 30_000), + maxOutputBytes: positiveLimit(options.maxOutputBytes, setting("MAX_OUTPUT_BYTES"), (kind === "CAPTURE" ? 10 : 1) * 1024 * 1024), + }; } -export function resolveProfileMaxOutputBytes(options = {}) { - if (Number.isFinite(options.maxOutputBytes) && options.maxOutputBytes >= 0) { - return options.maxOutputBytes; - } - return defaultProfileMaxOutputBytes; +function positiveLimit(option, env, fallback, max = maxTimerMs) { + const valid = (value) => Number.isFinite(value) && value > 0 && value <= max; + if (valid(option)) return Math.ceil(option); + const fromEnv = typeof env === "string" ? Number(env) : NaN; + return valid(fromEnv) ? Math.ceil(fromEnv) : fallback; } -function createCappedCollector(maxBytes) { +export function createCappedCollector(maxBytes) { const chunks = []; let size = 0; + let truncated = false; return { - chunks, + get truncated() { return truncated; }, push(chunk) { - if (size >= maxBytes) { - return; - } const buffer = Buffer.isBuffer(chunk) ? chunk : Buffer.from(chunk); - const room = maxBytes - size; - chunks.push(buffer.length > room ? buffer.subarray(0, room) : buffer); - size += Math.min(buffer.length, room); + const length = Math.min(buffer.length, maxBytes - size); + if (length < buffer.length) truncated = true; + if (length === 0) return; + chunks.push(Buffer.from(buffer.subarray(0, length))); + size += length; }, + text: () => Buffer.concat(chunks, size).toString("utf8"), }; } -async function readProcessStats(pid) { - if (!pid || process.platform === "win32") { - return { rssAvailable: false, rssKb: 0, cpuAvailable: false, cpuPercent: 0 }; - } - return new Promise((resolve) => { - const ps = spawn("ps", ["-o", "rss=", "-o", "%cpu=", "-p", String(pid)], { - stdio: ["ignore", "pipe", "ignore"], - }); - const chunks = []; - ps.stdout.on("data", (chunk) => chunks.push(chunk)); - ps.on("error", () => resolve({ rssAvailable: false, rssKb: 0, cpuAvailable: false, cpuPercent: 0 })); - ps.on("exit", () => { - const [rssRaw, cpuRaw] = Buffer.concat(chunks).toString("utf8").trim().split(/\s+/); - const rssKb = Number.parseInt(rssRaw, 10); - const cpuPercent = Number.parseFloat(cpuRaw); - const rssAvailable = Number.isFinite(rssKb); - const cpuAvailable = Number.isFinite(cpuPercent); - resolve({ - rssAvailable, - rssKb: rssAvailable ? rssKb : 0, - cpuAvailable, - cpuPercent: cpuAvailable ? cpuPercent : 0, - }); - }); +async function readProcessStats(pid, env, signal) { + const unavailable = { rssAvailable: false, rssKb: 0, cpuAvailable: false, cpuPercent: 0 }; + if (!pid || process.platform === "win32") return unavailable; + const { result } = startOwnedProcess({ + command: "ps", + args: ["-o", "rss=", "-o", "%cpu=", "-p", String(pid)], + env, + signal, + timeoutMs: 250, + killGraceMs: 50, + maxOutputBytes: 4096, }); + const outcome = await result; + if (outcome.exitCode !== 0 || outcome.outputTruncated) return unavailable; + const [rssRaw, cpuRaw] = outcome.stdout.trim().split(/\s+/); + const rssKb = Number.parseInt(rssRaw, 10); + const cpuPercent = Number.parseFloat(cpuRaw); + return { + rssAvailable: Number.isFinite(rssKb), + rssKb: Number.isFinite(rssKb) ? rssKb : 0, + cpuAvailable: Number.isFinite(cpuPercent), + cpuPercent: Number.isFinite(cpuPercent) ? cpuPercent : 0, + }; } function heapUsedMb() { return Math.round((process.memoryUsage().heapUsed / 1024 / 1024) * 10) / 10; } -function previewLines(chunks) { - return Buffer.concat(chunks).toString("utf8").trim().split("\n").slice(-2).join("\n"); +function previewLines(text) { + return text.trim().split("\n").slice(-2).join("\n"); } diff --git a/src/runtime-profile.js b/src/runtime-profile.js index d8f4df8..0bb1493 100644 --- a/src/runtime-profile.js +++ b/src/runtime-profile.js @@ -336,6 +336,7 @@ async function profileCommand(command, options) { timeoutMs: command.timeoutMs ?? options.timeoutMs, maxOutputBytes: command.maxOutputBytes ?? options.maxOutputBytes, killGraceMs: command.killGraceMs ?? options.killGraceMs, + signal: options.signal, }); } diff --git a/test/capture-timeout.test.js b/test/capture-timeout.test.js index 676f706..b5eb7e6 100644 --- a/test/capture-timeout.test.js +++ b/test/capture-timeout.test.js @@ -1,172 +1,223 @@ import assert from "node:assert/strict"; import { execFile } from "node:child_process"; -import { mkdtemp, writeFile } from "node:fs/promises"; +import { mkdtemp, readFile, rm, writeFile } from "node:fs/promises"; import os from "node:os"; import path from "node:path"; -import { promisify } from "node:util"; import { test } from "node:test"; -import { captureEntrypoint, classifyMockSdkCaptureError } from "../src/inspector.js"; +import { setTimeout as delay } from "node:timers/promises"; +import { promisify } from "node:util"; +import { captureEntrypoint } from "../src/inspector.js"; const execFileAsync = promisify(execFile); +const cliPath = path.resolve("src/cli.js"); -async function writeHangingRegisterPlugin(dir) { +async function fixture(t, source) { + const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-")); + t.after(async () => { + for (const name of ["pid", "pids"]) { + const text = await readFile(path.join(dir, name), "utf8").catch(() => ""); + for (const pid of text.split(/\s+/).map(Number).filter((value) => value > 0)) { + try { process.kill(pid, "SIGKILL"); } catch (error) { + if (error.code !== "ESRCH") throw error; + } + } + } + await rm(dir, { recursive: true, force: true }); + }); const entrypoint = path.join(dir, "index.mjs"); - await writeFile( - entrypoint, - [ - "export default {", - " async register() {", - " await new Promise(() => {", - " setInterval(() => {}, 1000);", - " });", - " }", - "};", - "", - ].join("\n"), - "utf8", - ); - return "index.mjs"; + await writeFile(entrypoint, source); + return { dir, entrypoint }; } -test("default mock-SDK capture timeout is a documented 30s budget", async () => { - const { defaultCaptureTimeoutMs } = await import("../src/inspector.js"); - assert.equal(defaultCaptureTimeoutMs, 30_000); -}); +function processExists(pid) { + try { + process.kill(pid, 0); + return true; + } catch (error) { + if (error.code === "ESRCH") return false; + throw error; + } +} -test("classifyMockSdkCaptureError treats a killed child as a capture timeout", () => { - const error = Object.assign(new Error("Command failed: node mock-sdk-capture-runner.js"), { - killed: true, - signal: "SIGTERM", - code: null, - stdout: "", - stderr: "", - }); +async function assertGone(pid) { + assert.ok(Number.isInteger(pid) && pid > 0); + for (let i = 0; i < 100 && processExists(pid); i += 1) await delay(10); + assert.equal(processExists(pid), false, `owned PID ${pid} survived capture`); +} - const classified = classifyMockSdkCaptureError(error); +for (const [name, register] of [ + ["busy loop", "while (true) {}"], + ["never-settling register", "await new Promise(() => { setInterval(() => {}, 1000); });"], + ["TERM-resistant register", "process.on('SIGTERM', () => {}); await new Promise(() => { setInterval(() => {}, 1000); });"], +]) { + test(`mock capture bounds a ${name}`, { timeout: 5000 }, async (t) => { + const { dir, entrypoint } = await fixture(t, ` + import { writeFileSync } from 'node:fs'; + export default { async register() { + writeFileSync(new URL('./pid', import.meta.url), String(process.pid)); + ${register} + } }; + `); + await assert.rejects(captureEntrypoint(entrypoint, { + cwd: dir, + mockSdk: true, + timeoutMs: 1000, + killGraceMs: 75, + }), (error) => { + assert.equal(error.failureClass, "capture-timeout"); + assert.match(error.message, /timed out after 1000ms/); + return true; + }); + await assertGone(Number(await readFile(path.join(dir, "pid"), "utf8"))); + }); +} - assert.equal(classified.failureClass, "capture-timeout"); - assert.match(classified.message, /timed out/i); +test("mock capture escalates after its leader exits and a descendant retains stdio", { + timeout: 8000, skip: process.platform === "win32", +}, async (t) => { + const descendant = "process.on('SIGTERM', () => {}); process.send('ready'); setInterval(() => {}, 1000);"; + const { dir, entrypoint } = await fixture(t, ` + import { spawn } from 'node:child_process'; + import { writeFileSync } from 'node:fs'; + export default { async register() { + const child = spawn(process.execPath, ['-e', ${JSON.stringify(descendant)}], { stdio: ['ignore', 'inherit', 'inherit', 'ipc'] }); + await new Promise((resolve) => child.once('message', resolve)); + writeFileSync(new URL('./pids', import.meta.url), process.pid + ' ' + child.pid); + process.on('SIGTERM', () => process.exit(0)); + await new Promise(() => { setInterval(() => {}, 1000); }); + } }; + `); + await assert.rejects(captureEntrypoint(entrypoint, { + cwd: dir, mockSdk: true, timeoutMs: 1500, killGraceMs: 75, + }), { failureClass: "capture-timeout" }); + const pids = (await readFile(path.join(dir, "pids"), "utf8")).split(/\s+/).map(Number); + for (const pid of pids) await assertGone(pid); }); -test( - "mock capture escalates to SIGKILL when register() ignores SIGTERM", - { timeout: 2500 }, - async () => { - const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-sigterm-")); - const entrypoint = path.join(dir, "index.mjs"); - await writeFile( - entrypoint, - [ - "export default {", - " async register() {", - " process.on('SIGTERM', () => {});", - " await new Promise(() => {", - " setInterval(() => {}, 1000);", - " });", - " },", - "};", - "", - ].join("\n"), - "utf8", - ); - - await assert.rejects( - () => - captureEntrypoint(entrypoint, { - cwd: dir, - pluginRoot: dir, - mockSdk: true, - timeoutMs: 200, - killGraceMs: 50, - }), - (error) => { - assert.equal(error.failureClass, "capture-timeout"); - assert.match(error.message, /timed out/i); - return true; - }, - ); - }, -); - -test( - "mock capture fails closed when register() never settles", - { timeout: 2500 }, - async () => { - const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-hang-")); - const entrypoint = await writeHangingRegisterPlugin(dir); - - await assert.rejects( - () => - captureEntrypoint(entrypoint, { - cwd: dir, - pluginRoot: dir, - mockSdk: true, - timeoutMs: 200, - }), - (error) => { - assert.equal(error.failureClass, "capture-timeout"); - assert.match(error.message, /timed out/i); - return true; - }, - ); - }, -); +test("mock capture cancellation cannot become success or wait for the timeout", { timeout: 5000 }, async (t) => { + const { dir, entrypoint } = await fixture(t, ` + import { writeFileSync } from 'node:fs'; + export default { async register() { + process.on('SIGTERM', () => process.exit(0)); + writeFileSync(new URL('./pid', import.meta.url), String(process.pid)); + await new Promise(() => { setInterval(() => {}, 1000); }); + } }; + `); + const controller = new AbortController(); + const pending = captureEntrypoint(entrypoint, { + cwd: dir, mockSdk: true, timeoutMs: 3000, killGraceMs: 75, signal: controller.signal, + }); + // Attach the rejection assertion before aborting; the child may close promptly. + const rejected = assert.rejects(pending, (error) => { + assert.equal(error.failureClass, "mock-sdk-capture-error"); + assert.match(error.message, /cancelled/); + return true; + }); + let pid; + for (let i = 0; i < 150; i += 1) { + pid = Number(await readFile(path.join(dir, "pid"), "utf8").catch(() => "")); + if (pid) break; + await delay(10); + } + controller.abort(); + await rejected; + await assertGone(pid); + await assert.rejects(captureEntrypoint(entrypoint, { + cwd: dir, mockSdk: true, signal: controller.signal, + }), /cancelled/); +}); -test( - "plugin-inspector capture --allow-execute prints complete JSON on the CLI pipe", - { timeout: 4000 }, - async () => { - const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-cli-ok-")); - const entrypoint = path.join(dir, "index.mjs"); - await writeFile( - entrypoint, - [ - "export default {", - " register() {", - " return undefined;", - " },", - "};", - "", - ].join("\n"), - "utf8", - ); - const cliPath = path.resolve("src/cli.js"); +test("mock capture bounds direct pipe floods and intercepted plugin output", { + timeout: 8000, skip: process.platform === "win32", +}, async (t) => { + const { dir, entrypoint } = await fixture(t, ` + export default { register() { + const chunk = 'x'.repeat(65536); + for (let i = 0; i < 64; i++) { process.stdout.write(chunk); process.stderr.write(chunk); } + } }; + `); + const captured = await captureEntrypoint(entrypoint, { cwd: dir, mockSdk: true, timeoutMs: 3000 }); + assert.equal(captured.status, "captured"); + assert.equal(Buffer.byteLength(captured.processOutput.stdout), 1024 * 1024); + assert.equal(Buffer.byteLength(captured.processOutput.stderr), 1024 * 1024); - const { stdout } = await execFileAsync( - process.execPath, - [cliPath, "capture", "index.mjs", "--allow-execute", "--mock-sdk"], - { cwd: dir }, - ); + const writer = ` + const { once } = require('node:events'); + const chunk = Buffer.alloc(65536, 'x'); + (async () => { + while (true) { + if (!process.stdout.write(chunk)) await once(process.stdout, 'drain'); + if (!process.stderr.write(chunk)) await once(process.stderr, 'drain'); + } + })(); + `; + await writeFile(entrypoint, ` + import { spawn } from 'node:child_process'; + import { writeFileSync } from 'node:fs'; + export default { async register() { + writeFileSync(new URL('./pid', import.meta.url), String(process.pid)); + const child = spawn(process.execPath, ['-e', ${JSON.stringify(writer)}], { stdio: ['ignore', 'inherit', 'inherit'] }); + writeFileSync(new URL('./pids', import.meta.url), String(child.pid)); + await new Promise(() => {}); + } }; + `); + await assert.rejects(captureEntrypoint(entrypoint, { + cwd: dir, mockSdk: true, timeoutMs: 1000, killGraceMs: 75, maxOutputBytes: 4096, + }), (error) => { + assert.equal(error.failureClass, "capture-timeout", error.message); + assert.equal(Buffer.byteLength(error.cause.stdout), 4096); + assert.equal(Buffer.byteLength(error.cause.stderr), 4096); + return true; + }); + await assertGone(Number(await readFile(path.join(dir, "pid"), "utf8"))); + await assertGone(Number(await readFile(path.join(dir, "pids"), "utf8"))); +}); - const parsed = JSON.parse(stdout); - assert.equal(parsed.status, "captured"); - assert.equal(parsed.mockSdk, true); - assert.ok(Array.isArray(parsed.captured)); - }, -); +test("valid JSON followed by a late registration rejection is not capture success", { timeout: 5000 }, async (t) => { + const { dir, entrypoint } = await fixture(t, ` + import { writeSync } from 'node:fs'; + export default { async register() { + writeSync(1, JSON.stringify({ status: 'captured', captured: [] })); + await new Promise((_, reject) => setTimeout(() => reject(new Error('late-fixture-rejection')), 25)); + } }; + `); + await assert.rejects(captureEntrypoint(entrypoint, { cwd: dir, mockSdk: true, timeoutMs: 3000 }), + { failureClass: "registration-execution-error", message: "Error: late-fixture-rejection" }); +}); -test( - "plugin-inspector capture --allow-execute times out a register() that never settles", - { timeout: 4000 }, - async () => { - const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-capture-cli-hang-")); - const entrypoint = await writeHangingRegisterPlugin(dir); - const cliPath = path.resolve("src/cli.js"); +test("CLI capture flushes large healthy JSON before shedding retained intervals", { timeout: 8000 }, async (t) => { + const { dir } = await fixture(t, ` + import { writeFileSync } from 'node:fs'; + export default { register() { + writeFileSync(new URL('./pid', import.meta.url), String(process.pid)); + process.stdout.write('x'.repeat(300000)); + setInterval(() => {}, 1000); + } }; + `); + const { stdout } = await execFileAsync(process.execPath, + [cliPath, "capture", "index.mjs", "--allow-execute", "--mock-sdk"], + { cwd: dir, timeout: 6000, env: { ...process.env, PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS: "3000" } }); + const parsed = JSON.parse(stdout); + assert.equal(parsed.status, "captured"); + assert.equal(parsed.mockSdk, true); + assert.equal(parsed.processOutput.stdout, "x".repeat(300000)); + await assertGone(Number(await readFile(path.join(dir, "pid"), "utf8"))); +}); - await assert.rejects( - () => - execFileAsync(process.execPath, [cliPath, "capture", entrypoint, "--allow-execute", "--mock-sdk"], { - cwd: dir, - env: { - ...process.env, - PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS: "200", - }, - timeout: 3000, - }), - (error) => { - assert.match(String(error.stderr ?? error.message), /timed out|capture-timeout/i); - return true; - }, - ); - }, -); +test("CLI capture uses its environment budget, not the outer watchdog", { timeout: 6000 }, async (t) => { + const { dir } = await fixture(t, ` + export default { async register() { await new Promise(() => { setInterval(() => {}, 1000); }); } }; + `); + await assert.rejects(execFileAsync(process.execPath, + [cliPath, "capture", "index.mjs", "--allow-execute", "--mock-sdk"], { + cwd: dir, + env: { ...process.env, PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS: "750" }, + timeout: 4500, + }), (error) => { + assert.equal(error.killed, false); + assert.equal(error.signal, null); + assert.notEqual(error.code, 0); + assert.match(error.stderr, /timed out after 750ms/); + return true; + }); +}); diff --git a/test/flush-write.test.js b/test/flush-write.test.js deleted file mode 100644 index a7ac44c..0000000 --- a/test/flush-write.test.js +++ /dev/null @@ -1,32 +0,0 @@ -import assert from "node:assert/strict"; -import { test } from "node:test"; -import { flushWrite } from "../src/flush-write.js"; - -test("flushWrite does not resolve until the write callback runs", async () => { - let callback; - const write = (_chunk, cb) => { - callback = cb; - return false; - }; - let settled = false; - const pending = flushWrite(write, '{"status":"captured"}\n').then(() => { - settled = true; - }); - - await Promise.resolve(); - assert.equal(settled, false); - callback(); - await pending; - assert.equal(settled, true); -}); - -test("flushWrite rejects when the write callback reports an error", async () => { - await assert.rejects( - () => - flushWrite((_chunk, cb) => { - cb(new Error("EPIPE")); - return false; - }, "x\n"), - /EPIPE/, - ); -}); diff --git a/test/process-profile.test.js b/test/process-profile.test.js index 682d6e7..3dfe1c6 100644 --- a/test/process-profile.test.js +++ b/test/process-profile.test.js @@ -1,122 +1,412 @@ import assert from "node:assert/strict"; -import { mkdtemp, writeFile } from "node:fs/promises"; +import { spawn } from "node:child_process"; +import { chmod, mkdir, mkdtemp, readFile, rm, writeFile } from "node:fs/promises"; import os from "node:os"; import path from "node:path"; import { test } from "node:test"; +import { setTimeout as delay } from "node:timers/promises"; import { buildImportLoopProfile } from "../src/import-loop-profile.js"; import { runProfiledProcess } from "../src/process-profile.js"; import { buildRuntimeProfile } from "../src/runtime-profile.js"; +const posixOnly = { skip: process.platform === "win32", timeout: 8000 }; +const exitOnTerm = "process.on('SIGTERM', () => process.exit(0)); setInterval(() => {}, 1000);"; + +async function tempDir(t) { + const dir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-process-")); + t.after(async () => { + await cleanupPids(path.join(dir, "pids")); + await rm(dir, { recursive: true, force: true }); + }); + return dir; +} + function processExists(pid) { - if (!pid) { - return false; - } try { process.kill(pid, 0); return true; - } catch { - return false; + } catch (error) { + if (error.code === "ESRCH") return false; + throw error; } } -test("default profile timeout and output caps are documented", async () => { - const { defaultProfileMaxOutputBytes, defaultProfileTimeoutMs } = await import("../src/process-profile.js"); - assert.equal(defaultProfileTimeoutMs, 30_000); - assert.equal(defaultProfileMaxOutputBytes, 1024 * 1024); -}); +async function assertGone(pid) { + assert.ok(Number.isInteger(pid) && pid > 0); + for (let i = 0; i < 100 && processExists(pid); i += 1) await delay(10); + assert.equal(processExists(pid), false, `owned PID ${pid} survived completion`); +} -test("profiled process that never exits is killed when the timeout expires", { timeout: 2500 }, async () => { +async function cleanupPids(file) { + const text = await readFile(file, "utf8").catch(() => ""); + for (const pid of text.trim().split(/\s+/).map(Number).filter((value) => value > 0)) { + try { process.kill(pid, "SIGKILL"); } catch (error) { + if (error.code !== "ESRCH") throw error; + } + } +} + +for (const [name, source] of [ + ["busy loop", "while (true) {}"], + ["retained interval", "setInterval(() => {}, 1000)"], + ["zero exit from SIGTERM", exitOnTerm], +]) { + test(`profile timeout fails and reaps a ${name}`, { timeout: 5000 }, async () => { + const result = await runProfiledProcess({ + command: process.execPath, + args: ["-e", source], + timeoutMs: 500, + killGraceMs: 75, + }); + assert.equal(result.timedOut, true); + assert.notEqual(result.exitCode, 0); + assert.ok(result.wallMs >= 450 && result.wallMs < 2500); + await assertGone(result.pid); + }); +} + +test("profile drains bounded stdout and stderr through close", { timeout: 5000 }, async () => { const result = await runProfiledProcess({ command: process.execPath, - args: ["-e", "setInterval(() => {}, 1000)"], - timeoutMs: 200, - pollMs: 25, + args: ["-e", "process.stdout.write('x'.repeat(200000)); process.stderr.write('y'.repeat(200000));"], + timeoutMs: 3000, + maxOutputBytes: 64, }); + assert.equal(result.exitCode, 0); + assert.equal(result.stdoutPreview, "x".repeat(64)); + assert.equal(result.stderrPreview, "y".repeat(64)); + await assertGone(result.pid); +}); +test("profile output flood stays capped until the production timeout", { timeout: 5000 }, async () => { + const result = await runProfiledProcess({ + command: process.execPath, + args: ["-e", "const fs = require('node:fs'); const b = Buffer.alloc(65536, 'x'); while (true) { fs.writeSync(1, b); fs.writeSync(2, b); }"], + timeoutMs: 500, + killGraceMs: 75, + maxOutputBytes: 4096, + }); assert.equal(result.timedOut, true); assert.notEqual(result.exitCode, 0); - assert.ok(result.wallMs >= 150); - assert.ok(result.wallMs < 1500); - assert.equal(processExists(result.pid), false); + assert.equal(Buffer.byteLength(result.stdoutPreview), 4096); + assert.equal(Buffer.byteLength(result.stderrPreview), 4096); + await assertGone(result.pid); }); -test("profiled process caps stdout and stderr and still returns", { timeout: 2500 }, async () => { +for (const mode of ["timeout", "normal exit", "cancel"]) { + test(`profile cleans a TERM-resistant descendant holding stdio after ${mode}`, posixOnly, async (t) => { + const dir = await tempDir(t); + const pidsFile = path.join(dir, "pids"); + const descendant = ` + process.on('SIGTERM', () => {}); + process.send('ready'); + setInterval(() => {}, 1000); + `; + const source = ` + const fs = require('node:fs'); + const child = require('node:child_process').spawn(process.execPath, ['-e', ${JSON.stringify(descendant)}], { stdio: ['ignore', 'inherit', 'inherit', 'ipc'] }); + child.once('message', () => { + fs.writeFileSync(${JSON.stringify(pidsFile)}, process.pid + ' ' + child.pid); + process.on('SIGTERM', () => process.exit(0)); + ${mode === "normal exit" ? "process.exit(0);" : "setInterval(() => {}, 1000);"} + }); + `; + const unrelated = spawn(process.execPath, ["-e", "setInterval(() => {}, 1000)"], { stdio: "ignore" }); + const unrelatedClosed = new Promise((resolve) => unrelated.once("close", resolve)); + t.after(async () => { unrelated.kill("SIGKILL"); await unrelatedClosed; }); + const controller = new AbortController(); + const pending = runProfiledProcess({ + command: process.execPath, + args: ["-e", source], + timeoutMs: 1500, + killGraceMs: 75, + signal: controller.signal, + }); + if (mode === "cancel") { + for (let i = 0; i < 100; i += 1) { + if (await readFile(pidsFile, "utf8").catch(() => "")) break; + await delay(10); + } + controller.abort(); + controller.abort(); + } + const result = await pending; + const pids = (await readFile(pidsFile, "utf8")).trim().split(/\s+/).map(Number); + assert.equal(result.timedOut, mode === "timeout"); + assert.equal(result.cancelled === true, mode === "cancel"); + assert.equal(result.exitCode === 0, mode === "normal exit"); + for (const pid of pids) await assertGone(pid); + assert.equal(processExists(unrelated.pid), true); + assert.ok(result.wallMs < 3500); + }); +} + +test("already cancelled profiles do not spawn a child", { timeout: 3000 }, async (t) => { + const dir = await tempDir(t); + const marker = path.join(dir, "ran"); const result = await runProfiledProcess({ command: process.execPath, - args: [ - "-e", - "process.stdout.write('x'.repeat(20000) + '\\nstdout-tail\\n'); process.stderr.write('y'.repeat(20000) + '\\nstderr-tail\\n');", - ], - timeoutMs: 2000, - maxOutputBytes: 64, + args: ["-e", `require('node:fs').writeFileSync(${JSON.stringify(marker)}, 'ran')`], + signal: AbortSignal.abort(), }); + assert.equal(result.cancelled, true); + assert.notEqual(result.exitCode, 0); + assert.equal(result.pid, undefined); + await assert.rejects(readFile(marker), { code: "ENOENT" }); +}); +test("profile budgets use valid API then environment values without a zero opt-out", { timeout: 10000 }, async (t) => { + for (const timeoutMs of [0, -1, NaN, Infinity, 2 ** 31]) { + await t.test(String(timeoutMs), async () => { + const result = await runProfiledProcess({ + command: process.execPath, + args: ["-e", "setTimeout(() => {}, 1200)"], + timeoutMs, + env: { ...process.env, PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS: "150" }, + }); + assert.equal(result.timedOut, true); + assert.notEqual(result.exitCode, 0); + assert.ok(result.wallMs < 1000); + }); + } + for (const options of [ + { timeoutMs: 2000, env: { ...process.env, PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS: "1" } }, + { env: { ...process.env, PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS: "1junk" } }, + ]) { + const result = await runProfiledProcess({ + command: process.execPath, + args: ["-e", "setTimeout(() => {}, 100)"], + ...options, + }); + assert.equal(result.exitCode, 0); + assert.equal(result.timedOut, false); + } +}); + +test("a stalled output-flooding ps cannot outlive the profile", posixOnly, async (t) => { + const dir = await tempDir(t); + const pidsFile = path.join(dir, "pids"); + const ps = path.join(dir, "ps"); + await writeFile(ps, `#!${process.execPath} + require('node:fs').appendFileSync(${JSON.stringify(pidsFile)}, process.pid + '\\n'); + process.on('SIGTERM', () => {}); + process.stdout.write('1 1 '.repeat(20000)); + setTimeout(() => process.exit(0), 1800); + `); + await chmod(ps, 0o755); + const originalPath = process.env.PATH; + process.env.PATH = `${dir}${path.delimiter}${originalPath ?? ""}`; + t.after(() => { process.env.PATH = originalPath; }); + const result = await runProfiledProcess({ + command: process.execPath, + args: ["-e", "setTimeout(() => {}, 500)"], + timeoutMs: 2000, + }); assert.equal(result.exitCode, 0); - assert.ok(Buffer.byteLength(result.stdoutPreview) <= 64); - assert.ok(Buffer.byteLength(result.stderrPreview) <= 64); + assert.ok(result.wallMs < 1500, `sampler delayed completion to ${result.wallMs}ms`); + assert.equal(result.statSampleCount, 0); + const pids = (await readFile(pidsFile, "utf8")).trim().split(/\s+/).map(Number); + assert.ok(pids.length > 0); + for (const pid of pids) await assertGone(pid); }); -test( - "buildRuntimeProfile times out a command that never exits", - { timeout: 4000 }, - async () => { - const profile = await buildRuntimeProfile({ - commands: [ - { - id: "hang", - label: "Hang", - category: "baseline", - args: ["-e", "setInterval(() => {}, 1000)"], - }, - ], - generatedAt: "test", - runs: 1, - timeoutMs: 200, +test("higher-level profiles reject a timeout even when SIGTERM exits zero", posixOnly, async (t) => { + const runtime = await buildRuntimeProfile({ + commands: [{ id: "hang", label: "Hang", category: "baseline", args: ["-e", exitOnTerm] }], + generatedAt: "test", + runs: 1, + timeoutMs: 500, + killGraceMs: 75, + }); + const hang = runtime.commands.find((command) => command.id === "hang"); + assert.ok(hang.exitCodes.every((code) => code !== 0)); + assert.ok(hang.samples.every((sample) => sample.timedOut)); + + const rootDir = await tempDir(t); + const entrypoint = path.join(rootDir, "index.mjs"); + await writeFile(entrypoint, "export default { register() {} };"); + const profile = await buildImportLoopProfile({ + baseline: false, + captureCommand: () => ({ command: process.execPath, args: ["-e", exitOnTerm] }), + entrypoint, + rootDir, + runs: 1, + env: { PLUGIN_INSPECTOR_PROFILE_TIMEOUT_MS: "500" }, + killGraceMs: 75, + }); + assert.equal(profile.summary.failCount, profile.samples.length); + assert.ok(profile.samples.every((sample) => sample.timedOut && sample.exitCode !== 0)); +}); + +for (const mode of ["timeout", "cancel", "success"]) { + test(`default import-loop owns its runner and descendants on ${mode}`, posixOnly, async (t) => { + const rootDir = await tempDir(t); + const entrypoint = path.join(rootDir, "index.mjs"); + const pidsFile = path.join(rootDir, "pids"); + const descendant = "process.on('SIGTERM', () => {}); process.send('ready'); setInterval(() => {}, 1000);"; + await writeFile(entrypoint, ` + import { spawn } from 'node:child_process'; + import { writeFileSync } from 'node:fs'; + export default { async register(api) { + const child = spawn(process.execPath, ['-e', ${JSON.stringify(descendant)}], { stdio: ['ignore', 'inherit', 'inherit', 'ipc'] }); + await new Promise((resolve) => child.once('message', resolve)); + writeFileSync(${JSON.stringify(pidsFile)}, process.pid + ' ' + child.pid); + api.on('before_tool_call', () => undefined); + ${mode === "success" ? "" : "await new Promise(() => { setInterval(() => {}, 1000); });"} + } }; + `); + const unrelated = spawn(process.execPath, ["-e", "setInterval(() => {}, 1000)"], { stdio: "ignore" }); + const unrelatedClosed = new Promise((resolve) => unrelated.once("close", resolve)); + t.after(async () => { unrelated.kill("SIGKILL"); await unrelatedClosed; }); + const controller = new AbortController(); + const pending = buildImportLoopProfile({ + rootDir, entrypoint, baseline: false, runs: 1, + timeoutMs: mode === "timeout" ? 1000 : 3000, + killGraceMs: 75, + signal: controller.signal, + env: { PLUGIN_INSPECTOR_CAPTURE_TIMEOUT_MS: "5000" }, }); + if (mode === "cancel") { + for (let i = 0; i < 150; i += 1) { + if (await readFile(pidsFile, "utf8").catch(() => "")) break; + await delay(10); + } + controller.abort(); + } + const profile = await pending; + const pids = (await readFile(pidsFile, "utf8")).trim().split(/\s+/).map(Number); + for (const pid of pids) await assertGone(pid); + assert.equal(processExists(unrelated.pid), true); + assert.equal(profile.summary.failCount, mode === "success" ? 0 : 1); + assert.equal(profile.samples[0].timedOut, mode === "timeout"); + assert.equal(profile.samples[0].cancelled, mode === "cancel"); + if (mode === "success") { + const artifact = JSON.parse(await readFile(path.join(rootDir, ".plugin-inspector/import-loop/capture-0.json"), "utf8")); + assert.equal(artifact.status, "captured"); + assert.equal(artifact.captured[0].name, "before_tool_call"); + } + }); +} + +test("default import-loop preserves captures over 1 MiB and retained timers", { timeout: 8000 }, async (t) => { + const rootDir = await tempDir(t); + const entrypoint = path.join(rootDir, "index.mjs"); + await writeFile(entrypoint, ` + import { writeFileSync } from 'node:fs'; + export default { register(api) { + writeFileSync(new URL('./pids', import.meta.url), String(process.pid)); + api.on('before_tool_call', () => undefined); + process.stdout.write('x'.repeat(700000)); + process.stderr.write('y'.repeat(700000)); + setInterval(() => {}, 1000); + } }; + `); + const profile = await buildImportLoopProfile({ + rootDir, entrypoint, baselineRuns: 1, runs: 1, timeoutMs: 3000, + }); + assert.equal(profile.summary.baselineFailCount, 0); + assert.equal(profile.summary.failCount, 0); + const artifactDir = path.join(rootDir, ".plugin-inspector/import-loop"); + const baseline = JSON.parse(await readFile(path.join(artifactDir, "baseline-0.json"), "utf8")); + const sampleJson = await readFile(path.join(artifactDir, "capture-0.json"), "utf8"); + const sample = JSON.parse(sampleJson); + assert.equal(baseline.status, "captured"); + assert.equal(baseline.captured.length, 1); + assert.equal(sample.captured[0].name, "before_tool_call"); + assert.ok(Buffer.byteLength(sampleJson) > 1024 * 1024); + assert.equal(sample.processOutput.stdout, "x".repeat(700000)); + assert.equal(sample.processOutput.stderr, "y".repeat(700000)); + await assertGone(Number(await readFile(path.join(rootDir, "pids"), "utf8"))); +}); + +test("default import-loop rejects capture results above the 10 MiB capture cap", { timeout: 5000 }, async (t) => { + const rootDir = await tempDir(t); + const entrypoint = path.join(rootDir, "index.mjs"); + await writeFile(entrypoint, ` + export default { register(api) { api.on('x'.repeat(6 * 1024 * 1024), () => undefined); } }; + `); + const profile = await buildImportLoopProfile({ + rootDir, entrypoint, baseline: false, runs: 1, timeoutMs: 3000, + }); + assert.equal(profile.summary.failCount, 1); + assert.notEqual(profile.samples[0].exitCode, 0); + assert.match(profile.samples[0].stderrPreview, /10485760-byte limit/); + await assert.rejects(readFile(path.join(rootDir, ".plugin-inspector/import-loop/capture-0.json")), { code: "ENOENT" }); +}); - const hang = profile.commands.find((command) => command.id === "hang"); - assert.ok(hang); - assert.ok(hang.exitCodes.some((code) => code !== 0)); - assert.ok(hang.samples.every((sample) => sample.timedOut === true)); - assert.ok(hang.wallMs.max < 2000); - }, -); - -test( - "buildImportLoopProfile times out a capture subprocess that never exits", - { timeout: 4000 }, - async () => { - const rootDir = await mkdtemp(path.join(os.tmpdir(), "plugin-inspector-import-loop-hang-")); - const hangScript = path.join(rootDir, "hang.mjs"); - const entrypoint = path.join(rootDir, "fixture.mjs"); - await writeFile(hangScript, "setInterval(() => {}, 1000);\n", "utf8"); - await writeFile( - entrypoint, - [ - "export default {", - " register(api) {", - " api.registerTool({ name: 'fixture_tool', inputSchema: { type: 'object' }, run() {} });", - " }", - "};", - "", - ].join("\n"), - "utf8", - ); +test("default import-loop cannot reuse a stale artifact after process.exit(0)", { timeout: 5000 }, async (t) => { + const rootDir = await tempDir(t); + const entrypoint = path.join(rootDir, "index.mjs"); + const outputDir = path.join(rootDir, "samples"); + const outputPath = path.join(outputDir, "capture-0.json"); + await mkdir(outputDir); + await writeFile(outputPath, JSON.stringify({ status: "captured", captured: [{ name: "stale" }] })); + await writeFile(entrypoint, "export default { register() { process.exit(0); } };"); + const profile = await buildImportLoopProfile({ rootDir, entrypoint, outputDir, baseline: false, runs: 1, timeoutMs: 3000 }); + assert.equal(profile.summary.failCount, 1); + assert.notEqual(profile.samples[0].exitCode, 0); + assert.match(profile.samples[0].stderrPreview, /Invalid capture artifact/); + await assert.rejects(readFile(outputPath), { code: "ENOENT" }); +}); +for (const [name, body, expected] of [ + ["artifact write failure", "mkdirSync(outputPath);", /EISDIR/], + ["oversized runner result", "process.stdout.write('x'.repeat(10000));", /byte limit/], + ["oversized file bypass", "writeFileSync(outputPath, JSON.stringify({ status: 'captured', captured: [], data: 'x'.repeat(10000) })); process.exit(0);", /byte limit/], + ["invalid current JSON", "writeFileSync(outputPath, JSON.stringify({ status: 'captured', captured: 'invalid' })); process.exit(0);", /captured contracts/], +]) { + test(`default import-loop reports ${name}`, { timeout: 5000 }, async (t) => { + const rootDir = await tempDir(t); + const entrypoint = path.join(rootDir, "index.mjs"); + const outputDir = path.join(rootDir, "samples"); + const outputPath = path.join(outputDir, "capture-0.json"); + await writeFile(entrypoint, ` + import { mkdirSync, writeFileSync } from 'node:fs'; + const outputPath = ${JSON.stringify(outputPath)}; + export default { register() { ${body} } }; + `); const profile = await buildImportLoopProfile({ - baseline: false, - captureCommand: () => ({ - command: process.execPath, - args: [hangScript], - }), - entrypoint, - rootDir, - runs: 1, - timeoutMs: 200, + rootDir, entrypoint, outputDir, baseline: false, runs: 1, timeoutMs: 3000, maxOutputBytes: 4096, }); + assert.equal(profile.summary.failCount, 1); + assert.notEqual(profile.samples[0].exitCode, 0); + assert.match(profile.samples[0].stderrPreview, expected); + }); +} - assert.ok(profile.summary.failCount > 0); - assert.ok(profile.samples.every((sample) => sample.timedOut === true)); - assert.ok(profile.samples.every((sample) => sample.wallMs < 2000)); - }, -); +test("custom import-loop commands retain arguments, cwd, env, and artifact ownership", { timeout: 5000 }, async (t) => { + const rootDir = await tempDir(t); + const cwd = path.join(rootDir, "custom"); + const outputDir = path.join(rootDir, "samples"); + const outputPath = path.join(outputDir, "capture-0.json"); + const captureScript = path.join(rootDir, "capture.mjs"); + await mkdir(cwd); + await mkdir(outputDir); + await writeFile(outputPath, "previous-custom-artifact"); + await writeFile(captureScript, ` + import assert from 'node:assert/strict'; + import { readFile, writeFile } from 'node:fs/promises'; + assert.equal(process.argv[2], 'custom-argument'); + assert.equal(process.cwd(), ${JSON.stringify(cwd)}); + assert.equal(process.env.CUSTOM_CAPTURE, 'present'); + assert.equal(await readFile(process.argv[3], 'utf8'), 'previous-custom-artifact'); + await writeFile(process.argv[3], JSON.stringify({ status: 'captured', captured: [{ name: 'custom' }] })); + `); + let calls = 0; + const profile = await buildImportLoopProfile({ + rootDir, outputDir, entrypoint: "custom-entry", baseline: false, runs: 1, + captureCommand: (options) => { + calls += 1; + assert.deepEqual(options, { entrypoint: "custom-entry", index: 0, outputPath, rootDir }); + return { + command: process.execPath, + args: [captureScript, "custom-argument", outputPath], + cwd, + env: { CUSTOM_CAPTURE: "present" }, + }; + }, + }); + assert.equal(calls, 1); + assert.equal(profile.summary.failCount, 0); + assert.equal(profile.summary.capturedCount, 1); +});