furyhawk/openclaw
1
0
Fork 0
mirror of https://github.com/openclaw/openclaw.git synced 2026-07-21 10:16:44 +00:00
Code Issues Packages Projects Releases Wiki Activity

test(gateway): harden watch regression diagnostics (#95473)

Browse Source 
Co-authored-by: kklouzal <kklouzal@users.noreply.github.com>
This commit is contained in:
Kyle Klouzal
2026-07-09 16:36:31 +01:00
committed by GitHub
co-authored by kklouzal
parent 20816f676f
commit 2e160718d4
2 changed files with 411 additions and 13 deletions
Download Patch File Download Diff File Expand all files Collapse all files
scripts/check-gateway-watch-regression.mjs
+124 -13
View File
@@ -50,10 +50,15 @@ const WATCH_GATEWAY_SKIP_ENV = {
* Maximum retained stdout/stderr text for gateway watch diagnostics.
*/
export const WATCH_LOG_CAPTURE_MAX_CHARS = 2 * 1024 * 1024;
export const WATCH_LOG_FAILURE_TAIL_CHARS = 12_000;
const WATCH_BUILD_DETECTION_MAX_CHARS = 4096;
const NON_NEGATIVE_INTEGER_PATTERN = /^(0|[1-9]\d*)$/u;
const ANSI_ESCAPE_PATTERN = new RegExp(`${String.fromCharCode(27)}\\[[0-?]*[ -/]*[@-~]`, "g");
function shellQuote(value) {
return `'${String(value).replaceAll("'", "'\\''")}'`;
}
/**
* Appends watch output while preserving only the diagnostic tail.
*/
@@ -71,6 +76,28 @@ function formatCapturedWatchLog(text, truncated) {
: text;
}
function formatWatchExit(exit) {
if (!exit) {
return "unknown exit";
}
const parts = [];
if (exit.code !== undefined) {
parts.push(`code ${exit.code === null ? "null" : exit.code}`);
}
if (exit.signal !== undefined) {
parts.push(`signal ${exit.signal === null ? "null" : exit.signal}`);
}
if (exit.error) {
parts.push(`error ${exit.error}`);
}
return parts.length > 0 ? parts.join(", ") : "unknown exit";
}
function readTextTail(filePath, maxChars = WATCH_LOG_FAILURE_TAIL_CHARS) {
const text = fs.readFileSync(filePath, "utf8");
return text.length <= maxChars ? text : text.slice(-maxChars);
}
/**
* Updates bounded watch-build detection state from new output.
*/
@@ -449,21 +476,43 @@ async function allocateLoopbackPort() {
});
}
function buildTimedWatchCommand(pidFilePath, timeFilePath, isolatedHomeDir, port) {
export function resolveTimedWatchShell(deps = {}) {
const existsSync = deps.existsSync ?? fs.existsSync;
for (const shellPath of ["/bin/bash", "/usr/bin/bash", "/bin/sh"]) {
if (existsSync(shellPath)) {
return shellPath;
}
}
return "/bin/sh";
}
export function buildTimedWatchCommand(
pidFilePath,
timeFilePath,
isolatedHomeDir,
port,
deps = {},
) {
const isolatedStateDir = path.join(isolatedHomeDir, ".openclaw");
const isolatedConfigPath = path.join(isolatedStateDir, "openclaw.json");
// CI env hooks can contain bash-only `declare` lines; running the watch shell
// under sh delays gateway readiness behind stderr noise before the idle window.
const shellPath = deps.shellPath ?? resolveTimedWatchShell(deps);
const nodeExecPath = deps.nodeExecPath ?? process.execPath;
const shellSource = [
'echo "$$" > "$OPENCLAW_WATCH_PID_FILE"',
'mkdir -p "$OPENCLAW_STATE_DIR"',
`printf '%s\n' '{"gateway":{"controlUi":{"enabled":false}},"plugins":{"enabled":false}}' > "$OPENCLAW_CONFIG_PATH"`,
`exec node scripts/watch-node.mjs gateway --force --allow-unconfigured --port ${String(port)} --token watch-regression-token`,
`exec ${shellQuote(nodeExecPath)} scripts/watch-node.mjs gateway --force --allow-unconfigured --port ${String(port)} --token watch-regression-token`,
].join("\n");
const nodeBinDir = path.dirname(nodeExecPath);
const env = {
OPENCLAW_WATCH_PID_FILE: pidFilePath,
HOME: isolatedHomeDir,
OPENCLAW_HOME: isolatedHomeDir,
OPENCLAW_CONFIG_PATH: isolatedConfigPath,
OPENCLAW_STATE_DIR: isolatedStateDir,
PATH: `${nodeBinDir}${path.delimiter}${process.env.PATH ?? ""}`,
XDG_CONFIG_HOME: path.join(isolatedHomeDir, ".config"),
...WATCH_GATEWAY_SKIP_ENV,
};
@@ -471,14 +520,14 @@ function buildTimedWatchCommand(pidFilePath, timeFilePath, isolatedHomeDir, port
if (process.platform === "darwin") {
return {
command: "/usr/bin/time",
args: ["-lp", "-o", timeFilePath, "/bin/sh", "-lc", shellSource],
args: ["-lp", "-o", timeFilePath, shellPath, "-lc", shellSource],
env,
};
}
if (!fs.existsSync("/usr/bin/time")) {
return {
command: "/bin/sh",
command: shellPath,
args: ["-lc", shellSource],
env,
};
@@ -491,7 +540,7 @@ function buildTimedWatchCommand(pidFilePath, timeFilePath, isolatedHomeDir, port
"__TIMING__ user=%U sys=%S elapsed=%e",
"-o",
timeFilePath,
"/bin/sh",
shellPath,
"-lc",
shellSource,
],
@@ -580,56 +629,78 @@ export async function runTimedWatch(options, outputDir, deps = {}) {
resolve({ code: null, signal: null, error: error.message });
});
});
const raceSpawnError = async (operation) =>
const childExit = new Promise((resolve) => {
child.once("exit", (code, signal) => resolve({ code, signal }));
});
const raceChildLifecycle = async (operation) =>
await Promise.race([
Promise.resolve(operation).then((value) => ({ type: "value", value })),
spawnErrorExit.then((value) => ({ type: "spawn-error", value })),
childExit.then((value) => ({ type: "child-exit", value })),
]);
let watchPid = null;
let exit = null;
let exitedBeforeReady = false;
let exitedBeforeStop = false;
for (let attempt = 0; attempt < 50; attempt += 1) {
if (fs.existsSync(pidFilePath)) {
watchPid = Number(fs.readFileSync(pidFilePath, "utf8").trim());
break;
}
const waitResult = await raceSpawnError(sleepMs(100));
const waitResult = await raceChildLifecycle(sleepMs(100));
if (waitResult.type === "spawn-error") {
exit = waitResult.value;
break;
}
if (waitResult.type === "child-exit") {
exit = waitResult.value;
exitedBeforeReady = true;
exitedBeforeStop = true;
break;
}
}
let readyBeforeWindow = false;
let idleCpuStartMs = null;
let idleCpuEndMs = null;
if (!exit) {
const readyResult = await raceSpawnError(
const readyResult = await raceChildLifecycle(
waitReady(() => `${stdout}\n${stderr}`, options.readyTimeoutMs),
);
if (readyResult.type === "spawn-error") {
exit = readyResult.value;
} else if (readyResult.type === "child-exit") {
exit = readyResult.value;
exitedBeforeReady = true;
exitedBeforeStop = true;
} else {
readyBeforeWindow = readyResult.value;
}
}
if (!exit && readyBeforeWindow && options.readySettleMs > 0) {
const settleResult = await raceSpawnError(sleepMs(options.readySettleMs));
const settleResult = await raceChildLifecycle(sleepMs(options.readySettleMs));
if (settleResult.type === "spawn-error") {
exit = settleResult.value;
} else if (settleResult.type === "child-exit") {
exit = settleResult.value;
exitedBeforeStop = true;
}
}
if (!exit) {
idleCpuStartMs = watchPid ? readCpuMs(watchPid) : null;
const windowResult = await raceSpawnError(sleepMs(options.windowMs));
const windowResult = await raceChildLifecycle(sleepMs(options.windowMs));
if (windowResult.type === "spawn-error") {
exit = windowResult.value;
} else if (windowResult.type === "child-exit") {
exit = windowResult.value;
exitedBeforeStop = true;
} else {
idleCpuEndMs = watchPid ? readCpuMs(watchPid) : null;
}
}
if (!exit) {
const stopResult = await raceSpawnError(stopChild(child, watchPid, options));
const stopResult = await raceChildLifecycle(stopChild(child, watchPid, options));
exit = stopResult.value;
}
@@ -646,6 +717,8 @@ export async function runTimedWatch(options, outputDir, deps = {}) {
timingFileMissing,
timing,
readyBeforeWindow,
exitedBeforeReady,
exitedBeforeStop,
idleCpuMs:
idleCpuStartMs == null || idleCpuEndMs == null
? null
@@ -809,9 +882,16 @@ export function collectGatewayWatchFindings(params) {
if (watchResult.spawnError) {
failures.push(`gateway:watch failed to start: ${watchResult.spawnError}`);
}
if (!watchResult.readyBeforeWindow) {
if (!watchResult.readyBeforeWindow && watchResult.exitedBeforeReady) {
failures.push(`gateway:watch exited before ready (${formatWatchExit(watchResult.exit)})`);
} else if (!watchResult.readyBeforeWindow) {
failures.push("gateway:watch did not report ready before the idle CPU window");
}
if (watchResult.readyBeforeWindow && watchResult.exitedBeforeStop) {
failures.push(
`gateway:watch exited before the idle CPU window completed (${formatWatchExit(watchResult.exit)})`,
);
}
if (watchResult.timingFileMissing && !Number.isFinite(watchResult.idleCpuMs)) {
failures.push(
"failed to collect CPU timing from the bounded gateway:watch run; timing artifact is missing",
@@ -850,6 +930,32 @@ export function collectGatewayWatchFindings(params) {
return { failures, warnings };
}
export function shouldReportDuplicateDistRuntimeRegression(failures) {
return failures.some((message) => message.startsWith("dist-runtime "));
}
function printWatchLogDiagnostics(watchResult) {
const artifacts = [
["stderr", watchResult.stderrPath],
["stdout", watchResult.stdoutPath],
];
for (const [label, filePath] of artifacts) {
if (!filePath || !fs.existsSync(filePath)) {
continue;
}
const tail = readTextTail(filePath).trimEnd();
if (!tail) {
warn(`gateway:watch ${label} artifact is empty (${filePath})`);
continue;
}
console.error(
`--- gateway:watch ${label} tail (${filePath}, last ${WATCH_LOG_FAILURE_TAIL_CHARS} chars) ---`,
);
console.error(tail);
console.error(`--- end gateway:watch ${label} tail ---`);
}
}
async function main() {
const options = parseArgs(process.argv.slice(2));
ensureDir(options.outputDir);
@@ -933,6 +1039,8 @@ async function main() {
cpuMs,
totalCpuMs,
readyBeforeWindow: watchResult.readyBeforeWindow,
exitedBeforeReady: watchResult.exitedBeforeReady,
exitedBeforeStop: watchResult.exitedBeforeStop,
cpuWarnMs: options.cpuWarnMs,
cpuFailMs: options.cpuFailMs,
distRuntimeFileGrowth,
@@ -944,6 +1052,8 @@ async function main() {
removedPaths: diff.removed.length,
watchExit: watchResult.exit,
spawnError: watchResult.spawnError,
stdoutPath: watchResult.stdoutPath,
stderrPath: watchResult.stderrPath,
timingFileMissing: watchResult.timingFileMissing,
timing: watchResult.timing,
};
@@ -972,7 +1082,8 @@ async function main() {
for (const message of failures) {
fail(message);
}
if (!failures.every((message) => message.includes("dirty watched source tree"))) {
printWatchLogDiagnostics(watchResult);
if (shouldReportDuplicateDistRuntimeRegression(failures)) {
fail(
"Possible duplicate dist-runtime graph regression: this can reintroduce split runtime personalities where plugins and core observe different global state, including Telegram missing /voice, /phone, or /pair.",
);
test/scripts/check-gateway-watch-regression.test.ts
+287
View File
@@ -6,11 +6,14 @@ import path from "node:path";
import { describe, expect, it, vi } from "vitest";
import {
appendBoundedWatchLog,
buildTimedWatchCommand,
collectGatewayWatchFindings,
hasGatewayReadyLog,
parseArgs,
resolveTimedWatchShell,
runTimedWatch,
readNonNegativeInteger,
shouldReportDuplicateDistRuntimeRegression,
shouldRefreshBuildStampForRestoredArtifacts,
stopTimedWatchChild,
updateWatchBuildDetection,
@@ -120,6 +123,52 @@ describe("check-gateway-watch-regression", () => {
expect(coalesced.reason).toBe("config_newer");
});
it("uses bash for timed watch commands when available", () => {
expect(
resolveTimedWatchShell({
existsSync: (candidate: string) => candidate === "/usr/bin/bash",
}),
).toBe("/usr/bin/bash");
const command = buildTimedWatchCommand(
"watch.pid",
"watch.time",
"/tmp/openclaw-watch",
19042,
{
existsSync: (candidate: string) =>
candidate === "/usr/bin/bash" || candidate === "/usr/bin/time",
},
);
const shellIndex = command.args.indexOf("/usr/bin/bash");
if (shellIndex >= 0) {
expect(command.args[shellIndex + 1]).toBe("-lc");
} else {
expect(command.command).toBe("/usr/bin/bash");
expect(command.args[0]).toBe("-lc");
}
});
it("runs gateway watch through the parent Node binary", () => {
const nodeExecPath = "/opt/hostedtoolcache/node/24.11.1/x64/bin/node";
const command = buildTimedWatchCommand(
"watch.pid",
"watch.time",
"/tmp/openclaw-watch",
19042,
{
existsSync: (candidate: string) =>
candidate === "/usr/bin/bash" || candidate === "/usr/bin/time",
nodeExecPath,
},
);
const shellSource = command.args.at(-1);
expect(shellSource).toContain(`exec '${nodeExecPath}' scripts/watch-node.mjs gateway --force`);
expect(command.env.PATH?.split(path.delimiter)[0]).toBe(path.dirname(nodeExecPath));
});
it("fails the regression gate when gateway watch never becomes ready", () => {
const findings = collectGatewayWatchFindings({
cpuMs: 0,
@@ -148,6 +197,84 @@ describe("check-gateway-watch-regression", () => {
expect(findings.warnings).toEqual([]);
});
it("reports early gateway watch exit before readiness distinctly", () => {
const findings = collectGatewayWatchFindings({
cpuMs: 0,
distRuntimeByteGrowth: 0,
distRuntimeFileGrowth: 0,
options: {
cpuFailMs: 8000,
cpuWarnMs: 1000,
distRuntimeByteGrowthMax: 2 * 1024 * 1024,
distRuntimeFileGrowthMax: 200,
windowMs: 10_000,
},
watchBuildReason: null,
watchResult: {
exit: { code: 1, signal: null },
exitedBeforeReady: true,
idleCpuMs: 0,
readyBeforeWindow: false,
spawnError: null,
timingFileMissing: false,
},
watchTriggeredBuild: false,
});
expect(findings.failures).toContain("gateway:watch exited before ready (code 1, signal null)");
expect(findings.failures).not.toContain(
"gateway:watch did not report ready before the idle CPU window",
);
expect(findings.warnings).toEqual([]);
});
it("reports gateway watch exit after readiness before the idle window completes", () => {
const findings = collectGatewayWatchFindings({
cpuMs: 0,
distRuntimeByteGrowth: 0,
distRuntimeFileGrowth: 0,
options: {
cpuFailMs: 8000,
cpuWarnMs: 1000,
distRuntimeByteGrowthMax: 2 * 1024 * 1024,
distRuntimeFileGrowthMax: 200,
windowMs: 10_000,
},
watchBuildReason: null,
watchResult: {
exit: { code: 0, signal: null },
exitedBeforeReady: false,
exitedBeforeStop: true,
idleCpuMs: 0,
readyBeforeWindow: true,
spawnError: null,
timingFileMissing: false,
},
watchTriggeredBuild: false,
});
expect(findings.failures).toContain(
"gateway:watch exited before the idle CPU window completed (code 0, signal null)",
);
expect(findings.warnings).toEqual([]);
});
it("reports duplicate dist-runtime regression only for dist-runtime growth failures", () => {
expect(
shouldReportDuplicateDistRuntimeRegression([
"gateway:watch did not report ready before the idle CPU window",
]),
).toBe(false);
expect(
shouldReportDuplicateDistRuntimeRegression(["dist-runtime file growth 201 exceeded max 200"]),
).toBe(true);
expect(
shouldReportDuplicateDistRuntimeRegression([
"dist-runtime apparent byte growth 2097153 exceeded max 2097152",
]),
).toBe(true);
});
it("refreshes restored build stamps only for skip-build config mtime drift", () => {
expect(
shouldRefreshBuildStampForRestoredArtifacts({
@@ -275,4 +402,164 @@ describe("check-gateway-watch-regression", () => {
fs.rmSync(outputDir, { recursive: true, force: true });
}
});
it("stops waiting for readiness when the watch process exits early", async () => {
const outputDir = fs.mkdtempSync(path.join(os.tmpdir(), "openclaw-gateway-watch-output-"));
const child = new EventEmitter() as EventEmitter & {
stderr: EventEmitter;
stdout: EventEmitter;
};
child.stderr = new EventEmitter();
child.stdout = new EventEmitter();
const sleep = vi.fn(() => new Promise<never>(() => {}));
const stopChild = vi.fn(async () => ({ code: null, signal: "SIGTERM" }));
const waitForGatewayReady = vi.fn(
() =>
new Promise<never>(() => {
// Child exit must win before readiness timeout.
}),
);
const spawn = vi.fn(() => {
process.nextTick(() => {
child.stderr.emit("data", "gateway startup failed\n");
child.emit("exit", 1, null);
});
return child;
});
try {
const result = await runTimedWatch(
{
readySettleMs: 0,
readyTimeoutMs: 30_000,
sigkillGraceMs: 1,
windowMs: 10_000,
},
outputDir,
{
allocateLoopbackPort: async () => 19042,
spawn,
sleep,
stopTimedWatchChild: stopChild,
waitForGatewayReady,
},
);
expect(result.exit).toEqual({ code: 1, signal: null });
expect(result.exitedBeforeReady).toBe(true);
expect(result.exitedBeforeStop).toBe(true);
expect(result.readyBeforeWindow).toBe(false);
expect(result.spawnError).toBeNull();
expect(fs.readFileSync(result.stderrPath, "utf8")).toContain("gateway startup failed");
expect(waitForGatewayReady).not.toHaveBeenCalled();
expect(stopChild).not.toHaveBeenCalled();
} finally {
fs.rmSync(outputDir, { recursive: true, force: true });
}
});
it("records a ready gateway watch exit during the settle window as unplanned", async () => {
const outputDir = fs.mkdtempSync(path.join(os.tmpdir(), "openclaw-gateway-watch-output-"));
const child = new EventEmitter() as EventEmitter & {
stderr: EventEmitter;
stdout: EventEmitter;
};
child.stderr = new EventEmitter();
child.stdout = new EventEmitter();
const stopChild = vi.fn(async () => ({ code: null, signal: "SIGTERM" }));
const sleep = vi.fn(
() =>
new Promise<never>(() => {
process.nextTick(() => {
child.emit("exit", 0, null);
});
}),
);
const spawn = vi.fn(() => {
fs.writeFileSync(path.join(outputDir, "watch.pid"), "1234\n", "utf8");
return child;
});
try {
const result = await runTimedWatch(
{
readySettleMs: 10_000,
readyTimeoutMs: 30_000,
sigkillGraceMs: 1,
windowMs: 10_000,
},
outputDir,
{
allocateLoopbackPort: async () => 19042,
spawn,
sleep,
stopTimedWatchChild: stopChild,
waitForGatewayReady: async () => true,
},
);
expect(result.exit).toEqual({ code: 0, signal: null });
expect(result.exitedBeforeReady).toBe(false);
expect(result.exitedBeforeStop).toBe(true);
expect(result.readyBeforeWindow).toBe(true);
expect(result.idleCpuMs).toBeNull();
expect(stopChild).not.toHaveBeenCalled();
} finally {
fs.rmSync(outputDir, { recursive: true, force: true });
}
});
it("records a ready gateway watch exit during the idle window as unplanned", async () => {
const outputDir = fs.mkdtempSync(path.join(os.tmpdir(), "openclaw-gateway-watch-output-"));
const child = new EventEmitter() as EventEmitter & {
stderr: EventEmitter;
stdout: EventEmitter;
};
child.stderr = new EventEmitter();
child.stdout = new EventEmitter();
const stopChild = vi.fn(async () => ({ code: null, signal: "SIGTERM" }));
const sleep = vi.fn(
() =>
new Promise<never>(() => {
process.nextTick(() => {
child.emit("exit", 0, null);
});
}),
);
const readProcessTreeCpuMs = vi.fn(() => 12);
const spawn = vi.fn(() => {
fs.writeFileSync(path.join(outputDir, "watch.pid"), "1234\n", "utf8");
return child;
});
try {
const result = await runTimedWatch(
{
readySettleMs: 0,
readyTimeoutMs: 30_000,
sigkillGraceMs: 1,
windowMs: 10_000,
},
outputDir,
{
allocateLoopbackPort: async () => 19042,
readProcessTreeCpuMs,
spawn,
sleep,
stopTimedWatchChild: stopChild,
waitForGatewayReady: async () => true,
},
);
expect(result.exit).toEqual({ code: 0, signal: null });
expect(result.exitedBeforeReady).toBe(false);
expect(result.exitedBeforeStop).toBe(true);
expect(result.readyBeforeWindow).toBe(true);
expect(result.idleCpuMs).toBeNull();
expect(readProcessTreeCpuMs).toHaveBeenCalledOnce();
expect(stopChild).not.toHaveBeenCalled();
} finally {
fs.rmSync(outputDir, { recursive: true, force: true });
}
});
});