golem15/msd-core
3
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix(#4012): make the artifact say whether the reporter ever loaded

Browse Source 
Down to 3 remote failures, all one chain. The explicit no-events reporting is
working — the diagnostic now states the events file does not exist, instead of
silently printing the generic message. But it then ASSERTED a cause: "the child
was killed before the reporter wrote even one event (process/spawn startup
stall, not a test hang)". That was a guess dressed as a finding, and the fixture
contradicts it: it starts a real test, so test:start should fire in milliseconds
against a 2000ms budget.

Two hypotheses remained and I could not separate them locally, because the local
test runner is hook-blocked here: either the custom reporter never LOADS in the
child, or it loads and no event reaches it before the SIGKILL.

Rather than guess a third time, the artifact now answers it. The reporter
appends a reporter:init line as its first action, before consuming anything, so
the file's contents discriminate: absent means the reporter never loaded;
init-only means it loaded and saw no test events; init plus events means it
works. The diagnostic has a branch for each and, where the cause is genuinely
unresolved, names both possibilities instead of picking one.

Also passes the reporter as a file:// URL via pathToFileURL. Node documents the
--test-reporter value as an import()-style specifier, and a bare absolute path
is not a portable one — notably on Windows. That is a correctness fix whichever
hypothesis holds, and it is a live candidate for the first. FIXED_OVERHEAD is
derived by reducing over the actual argv strings, so the longer URL is accounted
automatically.

Verified by execution, not assumption: composing the reporter against an EMPTY
event stream writes exactly one line, the init marker. That is the whole point
of the marker, so it is pinned by a test rather than left to inspection.

T1 stays red and untouched.

Verification runs on the remote runner.

Refs #4012
This commit is contained in:
sim
2026-08-28 19:41:32 -04:00
parent 5504724d7a
commit 444137e63a
3 changed files with 110 additions and 19 deletions
Download Patch File Download Diff File Expand all files Collapse all files

17
scripts/lib/ndjson-reporter.cjs
View File

@@ -57,6 +57,23 @@
// never leaves more than one dangling unparsable trailing line.
module.exports = async function ndjsonEventReporter(source) {
const eventsPath = process.env.GSD_RUN_TESTS_EVENTS_FILE;
// #3889: an init marker, written as this reporter's FIRST action — before
// the `for await` loop even begins consuming the event stream — so the
// events file's mere existence (and its exact contents) can distinguish
// "the reporter module never loaded in the child at all" (file absent)
// from "it loaded fine but no test:start reached it before the kill"
// (file contains only this one line) from "it's working" (file contains
// more than this line). Same appendFileSync durability rationale as every
// other write in this file: synchronous and unbuffered, so it survives an
// uncatchable SIGKILL landing a moment later.
if (eventsPath) {
try {
require('fs').appendFileSync(eventsPath, `${JSON.stringify({ type: 'reporter:init', ts: Date.now() })}\n`);
} catch {
// Best-effort, same as every other write below — must never crash the
// test run this reporter is only observing.
}
}
for await (const event of source) {
if (!eventsPath) continue; // no destination configured — nothing to record
if (

68
scripts/run-tests.cjs
View File

@@ -38,6 +38,7 @@
const { readdirSync, readFileSync, mkdtempSync, rmSync, unlinkSync, writeFileSync } = require('fs');
const { join, basename } = require('path');
const { tmpdir } = require('os');
const { pathToFileURL } = require('url');
const { execFileSync } = require('child_process');
const { ExitError, runMain } = require('./lib/cli-exit.cjs');
const {
@@ -702,15 +703,20 @@ function analyzeChunkEvents(eventsPath) {
raw = readFileSync(eventsPath, 'utf8');
} catch {
// The events file never existed — either GSD_RUN_TESTS_EVENTS_FILE never
// resolved to a writable path, or the child was killed before the ndjson
// reporter's very first appendFileSync. Distinct from "file exists but
// has zero parseable events" (readError=false, sawAnyEvent=false) so the
// diagnostic below can say explicitly WHICH of the two happened, rather
// than silently collapsing both into "no in-flight file identified".
return { files: [], staleMs: null, sawAnyEvent: false, readError: true };
// resolved to a writable path, or the reporter module never loaded in the
// child at all (the `reporter:init` marker below is the reporter's very
// FIRST action, before any test can run, so its absence pins the failure
// to reporter load/resolution, not to the tests). Distinct from "file
// exists but only the init marker was written" (readError=false,
// sawInitMarker=true, sawAnyEvent=false) so the diagnostic below can say
// explicitly WHICH of the two happened, rather than silently collapsing
// both into "no in-flight file identified".
return { files: [], staleMs: null, sawAnyEvent: false, sawInitMarker: false, readError: true };
}
const inFlight = new Map();
let lastTs = null;
let sawInitMarker = false;
let sawAnyEvent = false;
for (const line of raw.split('\n')) {
if (line.trim() === '') continue;
let evt;
@@ -720,6 +726,11 @@ function analyzeChunkEvents(eventsPath) {
continue; // truncated trailing line from a mid-write kill
}
if (typeof evt.ts === 'number') lastTs = evt.ts;
if (evt.type === 'reporter:init') {
sawInitMarker = true;
continue; // not a test event — never tracked in inFlight, never proof a test ran
}
sawAnyEvent = true;
const key = evt.testNumber !== undefined
? `${evt.file}::${evt.nesting}::${evt.testNumber}`
: `${evt.file}::${evt.name}`;
@@ -733,7 +744,8 @@ function analyzeChunkEvents(eventsPath) {
return {
files,
staleMs: lastTs !== null ? Date.now() - lastTs : null,
sawAnyEvent: lastTs !== null,
sawAnyEvent,
sawInitMarker,
readError: false,
};
}
@@ -1067,7 +1079,18 @@ function main() {
// races with, or is polluted by, another chunk's events. Deleted on the
// success path; kept only long enough to read back on a timeout.
const eventsDir = mkdtempSync(join(tmpdir(), 'gsd-run-tests-events-'));
const reporterModulePath = join(__dirname, 'lib', 'ndjson-reporter.cjs');
// #3889: Node documents `--test-reporter`'s value as "a string similar to
// those used in import() statements" (https://nodejs.org/api/test.html#--test-reporter),
// NOT a bare filesystem path — a bare absolute path is not a portable
// import specifier (notably on Windows, where `C:\...` is not valid
// import()able syntax). Converting through pathToFileURL is the fix that
// hardens reporter resolution against a possible root cause of #3889: the
// events file never being created at all because the reporter module
// itself never loaded in the child. This makes the resulting string
// LONGER than the bare path, which is why reporterOverhead/FIXED_OVERHEAD
// below are derived from the final reporterArgs strings, not a literal
// constant — they must reflect whatever this line actually produces.
const reporterModulePath = pathToFileURL(join(__dirname, 'lib', 'ndjson-reporter.cjs')).href;
const humanReporter = process.stdout.isTTY ? 'spec' : 'tap';
// Chunk index zero-padded to a fixed width so the events path's length is
// stable across chunks (kept for readability/debuggability; it no longer
@@ -1199,7 +1222,7 @@ function main() {
// this parent never saw the child's own stdout, so it cannot know
// otherwise). Falls back to "no file identified" rather than
// throwing when the reporter file is missing/empty/truncated.
const { files: inFlightFiles, staleMs, sawAnyEvent, readError } = analyzeChunkEvents(chunkEventsPath);
const { files: inFlightFiles, staleMs, sawAnyEvent, sawInitMarker, readError } = analyzeChunkEvents(chunkEventsPath);
const inFlightMsg = inFlightFiles.length > 0
? `In flight when killed (test:start with no matching pass/fail): ` +
`${inFlightFiles.map((f) => basename(f)).join(', ')} — last reporter event was ` +
@@ -1212,14 +1235,25 @@ function main() {
`diagnostic); suspect a leaked handle outside any single test, or an ` +
`after-tests hook.`
: readError
? `NO EVENTS COULD BE READ for this chunk — the companion reporter's events file ` +
`(GSD_RUN_TESTS_EVENTS_FILE) does not exist at all, so the child was killed ` +
`before the reporter wrote even one event (process/spawn startup stall, not a ` +
`test hang). This diagnostic could not identify an in-flight file.`
: `No reporter events were recorded before the kill — the companion reporter's ` +
`events file exists but is empty/unparseable, so even the first file in this ` +
`chunk may not have begun executing (process/spawn startup stall, not a test ` +
`hang). This diagnostic could not identify an in-flight file.`;
? `THE EVENTS FILE DOES NOT EXIST for this chunk — not even the reporter's own ` +
`\`reporter:init\` marker, which is the reporter module's first action before ` +
`it reads a single test event. Two possible causes, NOT distinguished by this ` +
`diagnostic: the ndjson reporter module never loaded in the child at all ` +
`(--test-reporter resolution failure), or the child was killed before the ` +
`reporter function was ever invoked (process/spawn startup stall). This ` +
`diagnostic could not identify an in-flight file.`
: sawInitMarker
? `THE REPORTER LOADED BUT RECORDED NO TEST EVENTS — the events file contains ` +
`only the reporter's own \`reporter:init\` marker, so the reporter module ` +
`was invoked and ran, but no \`test:start\` for any file in this chunk ` +
`reached it before the kill. Two possible causes, NOT distinguished by this ` +
`diagnostic: node --test itself stalled before dispatching any test file, or ` +
`the first file in this chunk hung/stalled before its first test began. This ` +
`diagnostic could not identify an in-flight file.`
: `No reporter events were recorded before the kill — the companion reporter's ` +
`events file exists but is empty/unparseable (no \`reporter:init\` marker and ` +
`no test events), so even the reporter's first appendFileSync may not have ` +
`completed. This diagnostic could not identify an in-flight file.`;
const table = loadTestTimings(process.env.RUN_TESTS_TIMINGS_FILE || DEFAULT_TIMINGS_PATH);
const ranked = rankChunkFilesByWeight(chunks[i], fileWeightOf(), table).join('\n');

44
tests/run-tests-harness.test.cjs
View File

@@ -934,8 +934,9 @@ test('hangs forever', () => new Promise(() => {}));
);
const rawContent = fs.readFileSync(eventsFile, 'utf8');
const lines = splitLines(rawContent.trim()).filter((l) => l.length > 0);
assert.strictEqual(lines.length, 2, `expected exactly 2 NDJSON lines; got:\n${lines.join('\n')}`);
const [start, pass] = lines.map((l) => JSON.parse(l));
assert.strictEqual(lines.length, 3, `expected exactly 3 NDJSON lines (init marker + 2 handled events); got:\n${lines.join('\n')}`);
const [init, start, pass] = lines.map((l) => JSON.parse(l));
assert.strictEqual(init.type, 'reporter:init');
assert.strictEqual(start.type, 'test:start');
assert.strictEqual(start.file, 'a.test.cjs');
assert.strictEqual(pass.type, 'test:pass');
@@ -950,6 +951,45 @@ test('hangs forever', () => new Promise(() => {}));
}
});
// #3889: the init marker is the reporter's FIRST action, written before
// the `for await` loop even begins — so it must land even when the
// source event stream yields ZERO events (e.g. the child is killed
// before node:test emits anything). This pins the marker's whole
// purpose: its presence alone proves the reporter module loaded and was
// invoked, independent of whether any test ever started.
test('the reporter writes only the init marker when the source yields zero events', async () => {
const reporter = require('../scripts/lib/ndjson-reporter.cjs');
const eventsFile = path.join(tmpDir, 'ndjson-reporter-init-only.ndjson');
const savedEventsFile = process.env.GSD_RUN_TESTS_EVENTS_FILE;
process.env.GSD_RUN_TESTS_EVENTS_FILE = eventsFile;
try {
async function* emptyEvents() {}
const result = await reporter(emptyEvents());
assert.strictEqual(
result ?? null,
null,
`expected the reporter to return nully even with zero source events; got ${JSON.stringify(result)}`,
);
const rawContent = fs.readFileSync(eventsFile, 'utf8');
const lines = splitLines(rawContent.trim()).filter((l) => l.length > 0);
assert.strictEqual(
lines.length,
1,
`expected exactly 1 NDJSON line (the init marker only); got:\n${lines.join('\n')}`,
);
const [init] = lines.map((l) => JSON.parse(l));
assert.strictEqual(init.type, 'reporter:init');
assert.strictEqual(typeof init.ts, 'number');
} finally {
if (savedEventsFile === undefined) {
delete process.env.GSD_RUN_TESTS_EVENTS_FILE;
} else {
process.env.GSD_RUN_TESTS_EVENTS_FILE = savedEventsFile;
}
cleanup(eventsFile);
}
});
// T4: the pre-existing timeout / abort / force-exit behavior (#1051)
// still holds with the reporter instrumentation wired in — the new
// --test-reporter flags must not change detection, the abort-on-timeout