fix(ci): trace test runner memory retention
This commit is contained in:
Vincent Koc
parent
b7c39aa4d4
commit
98298f7931
103
scripts/test-parallel-memory.mjs
Normal file
103
scripts/test-parallel-memory.mjs
Normal file
@ -0,0 +1,103 @@
|
||||
import { spawnSync } from "node:child_process";
|
||||
|
||||
const ESCAPE = String.fromCodePoint(27);
|
||||
const BELL = String.fromCodePoint(7);
|
||||
const ANSI_ESCAPE_PATTERN = new RegExp(
|
||||
// Strip CSI/OSC-style control sequences from Vitest output before parsing file lines.
|
||||
`${ESCAPE}(?:\\][^${BELL}]*(?:${BELL}|${ESCAPE}\\\\)|\\[[0-?]*[ -/]*[@-~]|[@-Z\\\\-_])`,
|
||||
"g",
|
||||
);
|
||||
|
||||
const COMPLETED_TEST_FILE_LINE_PATTERN =
|
||||
/(?<file>(?:src|extensions|test|ui)\/\S+?\.(?:live\.test|e2e\.test|test)\.ts)\s+\(.*\)\s+(?<duration>\d+(?:\.\d+)?)(?<unit>ms|s)\s*$/;
|
||||
|
||||
const PS_COLUMNS = ["pid=", "ppid=", "rss="];
|
||||
|
||||
function parseDurationMs(rawValue, unit) {
|
||||
const parsed = Number.parseFloat(rawValue);
|
||||
if (!Number.isFinite(parsed)) {
|
||||
return null;
|
||||
}
|
||||
return unit === "s" ? Math.round(parsed * 1000) : Math.round(parsed);
|
||||
}
|
||||
|
||||
function stripAnsi(text) {
|
||||
return text.replaceAll(ANSI_ESCAPE_PATTERN, "");
|
||||
}
|
||||
|
||||
export function parseCompletedTestFileLines(text) {
|
||||
return stripAnsi(text)
|
||||
.split(/\r?\n/u)
|
||||
.map((line) => {
|
||||
const match = line.match(COMPLETED_TEST_FILE_LINE_PATTERN);
|
||||
if (!match?.groups) {
|
||||
return null;
|
||||
}
|
||||
return {
|
||||
file: match.groups.file,
|
||||
durationMs: parseDurationMs(match.groups.duration, match.groups.unit),
|
||||
};
|
||||
})
|
||||
.filter((entry) => entry !== null);
|
||||
}
|
||||
|
||||
export function sampleProcessTreeRssKb(rootPid) {
|
||||
if (!Number.isInteger(rootPid) || rootPid <= 0 || process.platform === "win32") {
|
||||
return null;
|
||||
}
|
||||
|
||||
const result = spawnSync("ps", ["-axo", PS_COLUMNS.join(",")], {
|
||||
encoding: "utf8",
|
||||
});
|
||||
if (result.status !== 0 || result.error) {
|
||||
return null;
|
||||
}
|
||||
|
||||
const childPidsByParent = new Map();
|
||||
const rssByPid = new Map();
|
||||
for (const line of result.stdout.split(/\r?\n/u)) {
|
||||
const trimmed = line.trim();
|
||||
if (!trimmed) {
|
||||
continue;
|
||||
}
|
||||
const [pidRaw, parentRaw, rssRaw] = trimmed.split(/\s+/u);
|
||||
const pid = Number.parseInt(pidRaw ?? "", 10);
|
||||
const parentPid = Number.parseInt(parentRaw ?? "", 10);
|
||||
const rssKb = Number.parseInt(rssRaw ?? "", 10);
|
||||
if (!Number.isInteger(pid) || !Number.isInteger(parentPid) || !Number.isInteger(rssKb)) {
|
||||
continue;
|
||||
}
|
||||
const siblings = childPidsByParent.get(parentPid) ?? [];
|
||||
siblings.push(pid);
|
||||
childPidsByParent.set(parentPid, siblings);
|
||||
rssByPid.set(pid, rssKb);
|
||||
}
|
||||
|
||||
if (!rssByPid.has(rootPid)) {
|
||||
return null;
|
||||
}
|
||||
|
||||
let rssKb = 0;
|
||||
let processCount = 0;
|
||||
const queue = [rootPid];
|
||||
const visited = new Set();
|
||||
while (queue.length > 0) {
|
||||
const pid = queue.shift();
|
||||
if (pid === undefined || visited.has(pid)) {
|
||||
continue;
|
||||
}
|
||||
visited.add(pid);
|
||||
const currentRssKb = rssByPid.get(pid);
|
||||
if (currentRssKb !== undefined) {
|
||||
rssKb += currentRssKb;
|
||||
processCount += 1;
|
||||
}
|
||||
for (const childPid of childPidsByParent.get(pid) ?? []) {
|
||||
if (!visited.has(childPid)) {
|
||||
queue.push(childPid);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
return { rssKb, processCount };
|
||||
}
|
||||
@ -4,6 +4,7 @@ import os from "node:os";
|
||||
import path from "node:path";
|
||||
import { channelTestPrefixes } from "../vitest.channel-paths.mjs";
|
||||
import { isUnitConfigTestFile } from "../vitest.unit-paths.mjs";
|
||||
import { parseCompletedTestFileLines, sampleProcessTreeRssKb } from "./test-parallel-memory.mjs";
|
||||
import {
|
||||
appendCapturedOutput,
|
||||
hasFatalTestRunOutput,
|
||||
@ -184,6 +185,7 @@ const countExplicitEntryFilters = (entryArgs) => {
|
||||
const { fileFilters } = parsePassthroughArgs(entryArgs.slice(2));
|
||||
return fileFilters.length > 0 ? fileFilters.length : null;
|
||||
};
|
||||
const getExplicitEntryFilters = (entryArgs) => parsePassthroughArgs(entryArgs.slice(2)).fileFilters;
|
||||
const passthroughRequiresSingleRun = passthroughOptionArgs.some((arg) => {
|
||||
if (!arg.startsWith("-")) {
|
||||
return false;
|
||||
@ -707,6 +709,22 @@ const maxOldSpaceSizeMb = (() => {
|
||||
})();
|
||||
const formatElapsedMs = (elapsedMs) =>
|
||||
elapsedMs >= 1000 ? `${(elapsedMs / 1000).toFixed(1)}s` : `${Math.round(elapsedMs)}ms`;
|
||||
const formatMemoryKb = (rssKb) =>
|
||||
rssKb >= 1024 ** 2
|
||||
? `${(rssKb / 1024 ** 2).toFixed(2)}GiB`
|
||||
: rssKb >= 1024
|
||||
? `${(rssKb / 1024).toFixed(1)}MiB`
|
||||
: `${rssKb}KiB`;
|
||||
const formatMemoryDeltaKb = (rssKb) =>
|
||||
`${rssKb >= 0 ? "+" : "-"}${formatMemoryKb(Math.abs(rssKb))}`;
|
||||
const rawMemoryTrace = process.env.OPENCLAW_TEST_MEMORY_TRACE?.trim().toLowerCase();
|
||||
const memoryTraceEnabled =
|
||||
process.platform !== "win32" &&
|
||||
(rawMemoryTrace === "1" ||
|
||||
rawMemoryTrace === "true" ||
|
||||
(rawMemoryTrace !== "0" && rawMemoryTrace !== "false" && isCI));
|
||||
const memoryTracePollMs = Math.max(250, parseEnvNumber("OPENCLAW_TEST_MEMORY_TRACE_POLL_MS", 1000));
|
||||
const memoryTraceTopCount = Math.max(1, parseEnvNumber("OPENCLAW_TEST_MEMORY_TRACE_TOP_COUNT", 6));
|
||||
|
||||
const runOnce = (entry, extraArgs = []) =>
|
||||
new Promise((resolve) => {
|
||||
@ -718,6 +736,7 @@ const runOnce = (entry, extraArgs = []) =>
|
||||
entry.name === "extensions" && maxWorkers === 1 && entry.args.includes("--pool=vmForks")
|
||||
? entry.args.map((arg) => (arg === "--pool=vmForks" ? "--pool=forks" : arg))
|
||||
: entry.args;
|
||||
const explicitEntryFilters = getExplicitEntryFilters(entryArgs);
|
||||
const args = maxWorkers
|
||||
? [
|
||||
...entryArgs,
|
||||
@ -749,12 +768,115 @@ const runOnce = (entry, extraArgs = []) =>
|
||||
let fatalSeen = false;
|
||||
let childError = null;
|
||||
let child;
|
||||
let pendingLine = "";
|
||||
let memoryPollTimer = null;
|
||||
const memoryFileRecords = [];
|
||||
let initialTreeSample = null;
|
||||
let latestTreeSample = null;
|
||||
let peakTreeSample = null;
|
||||
const updatePeakTreeSample = (sample, reason) => {
|
||||
if (!sample) {
|
||||
return;
|
||||
}
|
||||
if (!peakTreeSample || sample.rssKb > peakTreeSample.rssKb) {
|
||||
peakTreeSample = { ...sample, reason };
|
||||
}
|
||||
};
|
||||
const captureTreeSample = (reason) => {
|
||||
if (!memoryTraceEnabled || !child?.pid) {
|
||||
return null;
|
||||
}
|
||||
const sample = sampleProcessTreeRssKb(child.pid);
|
||||
if (!sample) {
|
||||
return null;
|
||||
}
|
||||
latestTreeSample = sample;
|
||||
if (!initialTreeSample) {
|
||||
initialTreeSample = sample;
|
||||
}
|
||||
updatePeakTreeSample(sample, reason);
|
||||
return sample;
|
||||
};
|
||||
const logMemoryTraceForText = (text) => {
|
||||
if (!memoryTraceEnabled) {
|
||||
return;
|
||||
}
|
||||
const combined = `${pendingLine}${text}`;
|
||||
const lines = combined.split(/\r?\n/u);
|
||||
pendingLine = lines.pop() ?? "";
|
||||
const completedFiles = parseCompletedTestFileLines(lines.join("\n"));
|
||||
for (const completedFile of completedFiles) {
|
||||
const sample = captureTreeSample(completedFile.file);
|
||||
if (!sample) {
|
||||
continue;
|
||||
}
|
||||
const previousRssKb =
|
||||
memoryFileRecords.length > 0
|
||||
? (memoryFileRecords.at(-1)?.rssKb ?? initialTreeSample?.rssKb ?? sample.rssKb)
|
||||
: (initialTreeSample?.rssKb ?? sample.rssKb);
|
||||
const deltaKb = sample.rssKb - previousRssKb;
|
||||
const record = {
|
||||
...completedFile,
|
||||
rssKb: sample.rssKb,
|
||||
processCount: sample.processCount,
|
||||
deltaKb,
|
||||
};
|
||||
memoryFileRecords.push(record);
|
||||
console.log(
|
||||
`[test-parallel][mem] ${entry.name} file=${record.file} rss=${formatMemoryKb(
|
||||
record.rssKb,
|
||||
)} delta=${formatMemoryDeltaKb(record.deltaKb)} peak=${formatMemoryKb(
|
||||
peakTreeSample?.rssKb ?? record.rssKb,
|
||||
)} procs=${record.processCount}${record.durationMs ? ` duration=${formatElapsedMs(record.durationMs)}` : ""}`,
|
||||
);
|
||||
}
|
||||
};
|
||||
const logMemoryTraceSummary = () => {
|
||||
if (!memoryTraceEnabled) {
|
||||
return;
|
||||
}
|
||||
captureTreeSample("close");
|
||||
const fallbackRecord =
|
||||
memoryFileRecords.length === 0 &&
|
||||
explicitEntryFilters.length === 1 &&
|
||||
latestTreeSample &&
|
||||
initialTreeSample
|
||||
? [
|
||||
{
|
||||
file: explicitEntryFilters[0],
|
||||
deltaKb: latestTreeSample.rssKb - initialTreeSample.rssKb,
|
||||
},
|
||||
]
|
||||
: [];
|
||||
const totalDeltaKb =
|
||||
initialTreeSample && latestTreeSample
|
||||
? latestTreeSample.rssKb - initialTreeSample.rssKb
|
||||
: 0;
|
||||
const topGrowthFiles = [...memoryFileRecords, ...fallbackRecord]
|
||||
.filter((record) => record.deltaKb > 0 && typeof record.file === "string")
|
||||
.toSorted((left, right) => right.deltaKb - left.deltaKb)
|
||||
.slice(0, memoryTraceTopCount)
|
||||
.map((record) => `${record.file}:${formatMemoryDeltaKb(record.deltaKb)}`);
|
||||
console.log(
|
||||
`[test-parallel][mem] summary ${entry.name} files=${memoryFileRecords.length} peak=${formatMemoryKb(
|
||||
peakTreeSample?.rssKb ?? 0,
|
||||
)} totalDelta=${formatMemoryDeltaKb(totalDeltaKb)} peakAt=${
|
||||
peakTreeSample?.reason ?? "n/a"
|
||||
} top=${topGrowthFiles.length > 0 ? topGrowthFiles.join(", ") : "none"}`,
|
||||
);
|
||||
};
|
||||
try {
|
||||
child = spawn(pnpm, args, {
|
||||
stdio: ["inherit", "pipe", "pipe"],
|
||||
env: { ...process.env, VITEST_GROUP: entry.name, NODE_OPTIONS: resolvedNodeOptions },
|
||||
shell: isWindows,
|
||||
});
|
||||
captureTreeSample("spawn");
|
||||
if (memoryTraceEnabled) {
|
||||
memoryPollTimer = setInterval(() => {
|
||||
captureTreeSample("poll");
|
||||
}, memoryTracePollMs);
|
||||
}
|
||||
} catch (err) {
|
||||
console.error(`[test-parallel] spawn failed: ${String(err)}`);
|
||||
resolve(1);
|
||||
@ -765,12 +887,14 @@ const runOnce = (entry, extraArgs = []) =>
|
||||
const text = chunk.toString();
|
||||
fatalSeen ||= hasFatalTestRunOutput(`${output}${text}`);
|
||||
output = appendCapturedOutput(output, text);
|
||||
logMemoryTraceForText(text);
|
||||
process.stdout.write(chunk);
|
||||
});
|
||||
child.stderr?.on("data", (chunk) => {
|
||||
const text = chunk.toString();
|
||||
fatalSeen ||= hasFatalTestRunOutput(`${output}${text}`);
|
||||
output = appendCapturedOutput(output, text);
|
||||
logMemoryTraceForText(text);
|
||||
process.stderr.write(chunk);
|
||||
});
|
||||
child.on("error", (err) => {
|
||||
@ -778,8 +902,12 @@ const runOnce = (entry, extraArgs = []) =>
|
||||
console.error(`[test-parallel] child error: ${String(err)}`);
|
||||
});
|
||||
child.on("close", (code, signal) => {
|
||||
if (memoryPollTimer) {
|
||||
clearInterval(memoryPollTimer);
|
||||
}
|
||||
children.delete(child);
|
||||
const resolvedCode = resolveTestRunExitCode({ code, signal, output, fatalSeen, childError });
|
||||
logMemoryTraceSummary();
|
||||
console.log(
|
||||
`[test-parallel] done ${entry.name} code=${String(resolvedCode)} elapsed=${formatElapsedMs(Date.now() - startedAt)}`,
|
||||
);
|
||||
|
||||
@ -1,4 +1,5 @@
|
||||
import { describe, expect, it } from "vitest";
|
||||
import { parseCompletedTestFileLines } from "../../scripts/test-parallel-memory.mjs";
|
||||
import {
|
||||
appendCapturedOutput,
|
||||
hasFatalTestRunOutput,
|
||||
@ -44,3 +45,35 @@ describe("scripts/test-parallel fatal output guard", () => {
|
||||
expect(appendCapturedOutput(output, "defg", 5)).toBe("cdefg");
|
||||
});
|
||||
});
|
||||
|
||||
describe("scripts/test-parallel memory trace parsing", () => {
|
||||
it("extracts completed test file lines from colored Vitest output", () => {
|
||||
const output = [
|
||||
"\u001B[32m✓\u001B[39m src/config/doc-baseline.test.ts \u001B[2m(\u001B[22m\u001B[2m8 tests\u001B[22m\u001B[2m)\u001B[22m\u001B[33m 46424\u001B[2mms\u001B[22m\u001B[39m",
|
||||
" \u001B[32m✓\u001B[39m src/infra/restart.test.ts (5 tests) 4.2s",
|
||||
].join("\n");
|
||||
|
||||
expect(parseCompletedTestFileLines(output)).toEqual([
|
||||
{
|
||||
file: "src/config/doc-baseline.test.ts",
|
||||
durationMs: 46_424,
|
||||
},
|
||||
{
|
||||
file: "src/infra/restart.test.ts",
|
||||
durationMs: 4_200,
|
||||
},
|
||||
]);
|
||||
});
|
||||
|
||||
it("ignores non-file summary lines", () => {
|
||||
expect(
|
||||
parseCompletedTestFileLines(
|
||||
[
|
||||
" Test Files 2 passed (2)",
|
||||
" Tests 30 passed (30)",
|
||||
"[test-parallel] done unit code=0 elapsed=68.8s",
|
||||
].join("\n"),
|
||||
),
|
||||
).toEqual([]);
|
||||
});
|
||||
});
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user