diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 385a7fb1..ca8ef41e 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -57,12 +57,27 @@ jobs: - name: Run tests if: matrix.os != 'ubuntu-latest' || matrix.node-version != '22' + env: + VITEST_GUARD_LOG_PATH: ${{ runner.temp }}/vitest-guard-test-run-${{ matrix.os }}-node${{ matrix.node-version }}.log run: npm run test:run - name: Run tests with coverage thresholds if: matrix.os == 'ubuntu-latest' && matrix.node-version == '22' + env: + VITEST_GUARD_LOG_PATH: ${{ runner.temp }}/vitest-guard-test-coverage-${{ matrix.os }}-node${{ matrix.node-version }}.log run: npm run test:coverage + - name: Upload raw vitest logs on failure + if: failure() + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 + with: + name: vitest-guard-logs-${{ github.run_id }}-${{ github.run_attempt }}-${{ matrix.os }}-node${{ matrix.node-version }} + path: | + ${{ runner.temp }}/vitest-guard-test-run-${{ matrix.os }}-node${{ matrix.node-version }}.log + ${{ runner.temp }}/vitest-guard-test-coverage-${{ matrix.os }}-node${{ matrix.node-version }}.log + if-no-files-found: ignore + retention-days: 7 + - name: Build run: npm run build diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml index aa2c155b..b37f1a41 100644 --- a/.github/workflows/release.yml +++ b/.github/workflows/release.yml @@ -129,8 +129,19 @@ jobs: run: npm run typecheck - name: Run tests + env: + VITEST_GUARD_LOG_PATH: ${{ runner.temp }}/vitest-guard-test-run-ubuntu-latest-node20.log run: npm run test:run + - name: Upload raw vitest logs on failure + if: failure() + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 + with: + name: vitest-guard-logs-${{ github.run_id }}-${{ github.run_attempt }}-release-ubuntu-latest-node20 + path: ${{ runner.temp }}/vitest-guard-test-run-ubuntu-latest-node20.log + if-no-files-found: ignore + retention-days: 7 + - name: Build run: npm run build diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 22e55118..a471d71d 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -32,6 +32,8 @@ npm run test:run npm run build ``` +Both `npm run test:run` and `npm run test:coverage` are guarded: they fail on an absorbed Vitest forks-worker startup failure even when Vitest itself prints a green summary. + For documentation-only changes, still run `npm run typecheck` and `npm run build` when practical so broken links in generated docs or TypeScript examples do not slip through. If a command is not relevant or cannot be run locally, note that in the pull request. If you are changing packaging or install behavior, also run: diff --git a/docs/release.md b/docs/release.md index d542c19e..d3a054a6 100644 --- a/docs/release.md +++ b/docs/release.md @@ -52,6 +52,8 @@ npm pack --dry-run npm sbom --sbom-format cyclonedx > sbom.cdx.json ``` +The `npm run test:run` and `npm run test:coverage` commands are guarded and fail when their raw logs contain an absorbed Vitest forks-worker startup failure, even if Vitest reports a green summary. + Run `npm run qualify:validate` when that script is present. Its failure is a release blocker; when it is absent, record that qualification was unavailable rather than presenting it as passed. The release pipeline's qualification gate (`.github/scripts/check-qualification-gate.mjs`) actually has three outcomes, not two, and the third is intentional: diff --git a/package.json b/package.json index fc31701d..ef632477 100644 --- a/package.json +++ b/package.json @@ -57,8 +57,8 @@ "build": "tsc -p tsconfig.build.json", "typecheck": "tsc --noEmit", "test": "vitest", - "test:run": "vitest run", - "test:coverage": "vitest run --coverage", + "test:run": "node scripts/run-guarded-vitest.mjs run", + "test:coverage": "node scripts/run-guarded-vitest.mjs run --coverage", "prepack": "npm run clean && npm run build", "pack:dry-run": "npm pack --dry-run", "publish:public": "npm publish --access public", diff --git a/scripts/run-guarded-vitest.mjs b/scripts/run-guarded-vitest.mjs new file mode 100644 index 00000000..98221012 --- /dev/null +++ b/scripts/run-guarded-vitest.mjs @@ -0,0 +1,311 @@ +import { spawn } from 'node:child_process' +import { + createWriteStream, + mkdtempSync, + mkdirSync, + readFileSync, + rmSync, +} from 'node:fs' +import { createRequire } from 'node:module' +import { constants, tmpdir } from 'node:os' +import { dirname, isAbsolute, join, resolve } from 'node:path' +import { fileURLToPath } from 'node:url' + +import { + assertCleanVitestLogs, + formatReport, + WORKER_FAILURE_SIGNATURES, +} from '../.github/scripts/assert-clean-vitest-log.mjs' + +const require = createRequire(import.meta.url) + +export { WORKER_FAILURE_SIGNATURES } + +export function resolveVitestEntry(env = process.env) { + // Test-only injection seam: fixtures can stand in for Vitest without replacing its real + // package or platform-specific bin shims. Repository npm scripts never set this variable. + if (env.VITEST_GUARD_EXEC_OVERRIDE !== undefined) { + if (!env.VITEST_GUARD_EXEC_OVERRIDE || !isAbsolute(env.VITEST_GUARD_EXEC_OVERRIDE)) { + throw new Error('VITEST_GUARD_EXEC_OVERRIDE must be an absolute path') + } + return env.VITEST_GUARD_EXEC_OVERRIDE + } + + const packagePath = require.resolve('vitest/package.json') + const packageJson = JSON.parse(readFileSync(packagePath, 'utf8')) + const binPath = typeof packageJson.bin === 'string' ? packageJson.bin : packageJson.bin?.vitest + if (typeof binPath !== 'string' || binPath.length === 0) { + throw new Error(`Unable to resolve the vitest executable from ${packagePath}`) + } + return join(dirname(packagePath), binPath) +} + +export function createLogTarget(env = process.env) { + if (env.VITEST_GUARD_LOG_PATH !== undefined) { + if (!env.VITEST_GUARD_LOG_PATH) { + throw new Error('VITEST_GUARD_LOG_PATH must not be empty') + } + const logPath = env.VITEST_GUARD_LOG_PATH + mkdirSync(dirname(logPath), { recursive: true }) + return { logPath, tempDirectory: undefined } + } + + const tempDirectory = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-')) + return { logPath: join(tempDirectory, 'output.log'), tempDirectory } +} + +export function signalExitCode(signal) { + const signalNumber = constants.signals[signal] + return typeof signalNumber === 'number' ? 128 + signalNumber : 1 +} + +// Forwards at most one signal to `child`, ever, regardless of how many times the returned +// function is invoked or how quickly. This is a one-shot latch, not a per-signal-type guard: +// once we have decided to forward a termination signal, the child is already on its way down, +// and a second delivery only risks Vitest treating it as an escalation (a second SIGINT/SIGTERM +// typically forces a hard stop instead of a graceful one). The `forwarded` flag is set +// synchronously, in the same tick as the check, so a second signal arriving before Node has +// updated `child.exitCode`/`child.signalCode` cannot slip past the guard the way a check against +// only those two fields could -- that race is exactly what let two rapid signals both pass the +// old exitCode/signalCode-only check and each call `child.kill()`. +export function createSignalForwarder(child) { + let forwarded = false + return (signal) => { + if (forwarded) { + return false + } + if (child.exitCode !== null || child.signalCode !== null) { + return false + } + forwarded = true + child.kill(signal) + return true + } +} + +function waitForReadable(stream) { + return new Promise((resolveDone) => { + if (stream.readableEnded || stream.destroyed) { + resolveDone() + return + } + stream.once('end', resolveDone) + stream.once('close', resolveDone) + stream.once('error', resolveDone) + }) +} + +function waitForClose(stream) { + return new Promise((resolveDone) => { + if (stream.closed) { + resolveDone() + return + } + stream.once('close', resolveDone) + }) +} + +async function openLog(logPath) { + const stream = createWriteStream(logPath, { flags: 'w' }) + let writeError + stream.on('error', (error) => { + writeError ??= error + }) + + await new Promise((resolveOpen, rejectOpen) => { + stream.once('open', resolveOpen) + stream.once('error', rejectOpen) + }) + + return { stream, getWriteError: () => writeError } +} + +function errorMessage(error) { + return error instanceof Error ? error.message : String(error) +} + +function reportLogPath(logPath) { + console.error(`Retained vitest log path: ${logPath}`) +} + +function reportChildFailure(outcome) { + if (outcome.signal !== null) { + console.error(`=== CHILD PROCESS FAILURE (signal ${outcome.signal}) ===`) + } else if (outcome.code !== 0 && outcome.code !== null) { + console.error(`=== CHILD PROCESS FAILURE (exit code ${outcome.code}) ===`) + } +} + +function outcomeExitCode(outcome) { + if (outcome.signal !== null) { + return signalExitCode(outcome.signal) + } + return outcome.code && outcome.code > 0 ? outcome.code : 1 +} + +export async function runGuardedVitest(forwardedArgs, env = process.env) { + let target + try { + target = createLogTarget(env) + } catch (error) { + console.error('=== VITEST LOG FAILURE (could not prepare the log path) ===') + console.error(errorMessage(error)) + if (env.VITEST_GUARD_LOG_PATH !== undefined) { + reportLogPath(env.VITEST_GUARD_LOG_PATH) + } else { + console.error('Retained vitest log path: unavailable because the temporary log directory could not be created') + } + return 1 + } + + let vitestEntryPath + try { + vitestEntryPath = resolveVitestEntry(env) + } catch (error) { + console.error('=== VITEST EXECUTABLE RESOLUTION FAILURE ===') + console.error(errorMessage(error)) + reportLogPath(target.logPath) + return 1 + } + + let log + try { + log = await openLog(target.logPath) + } catch (error) { + console.error('=== VITEST LOG FAILURE (could not create the log file) ===') + console.error(errorMessage(error)) + reportLogPath(target.logPath) + return 1 + } + const { stream: logStream, getWriteError } = log + + // POSIX only: give the child its own process group instead of inheriting ours. Without this, + // an interactive Ctrl-C sends SIGINT to the whole foreground process group -- the child + // receives it directly from the terminal at the same moment our own SIGINT handler below also + // fires and explicitly forwards a second SIGINT via `child.kill()`. Vitest (like most tools) + // treats a second termination signal as an escalation to a forced stop, so one Ctrl-C could + // silently turn into a hard kill. Detaching the child's process group makes this wrapper's + // explicit forward the only delivery path, on every platform behavior source (interactive + // terminal or a targeted `kill `), so the one-shot latch below is the single point of + // truth for whether the child has been signaled. Trade-off, accepted deliberately: an + // uncatchable process-group-wide signal (e.g. `kill -9 -`, or Ctrl-\ SIGQUIT) sent to the + // original group no longer automatically reaches the now-detached child, so it could be + // orphaned in that specific, rare case; SIGKILL/SIGQUIT can never be forwarded by any wrapper + // design (they cannot be caught), and this only changes what happens to an already-uncatchable + // signal, not whether SIGINT/SIGTERM are handled. Not applied on Windows, which has no + // equivalent POSIX process-group signal semantics for `spawn` to isolate against. + let child + try { + child = spawn(process.execPath, [vitestEntryPath, ...forwardedArgs], { + cwd: process.cwd(), + stdio: ['inherit', 'pipe', 'pipe'], + detached: process.platform !== 'win32', + }) + } catch (error) { + logStream.end() + await waitForClose(logStream) + console.error('=== VITEST CHILD SPAWN FAILURE ===') + console.error(errorMessage(error)) + reportLogPath(target.logPath) + return 1 + } + + child.stdout.pipe(process.stdout, { end: false }) + child.stderr.pipe(process.stderr, { end: false }) + child.stdout.pipe(logStream, { end: false }) + child.stderr.pipe(logStream, { end: false }) + + const outputDone = Promise.all([waitForReadable(child.stdout), waitForReadable(child.stderr)]) + const forwardSignal = createSignalForwarder(child) + const forwardSigint = () => forwardSignal('SIGINT') + const forwardSigterm = () => forwardSignal('SIGTERM') + process.on('SIGINT', forwardSigint) + process.on('SIGTERM', forwardSigterm) + + let outcome + let spawnError + try { + outcome = await new Promise((resolveExit) => { + child.once('error', (error) => { + spawnError = error + resolveExit(undefined) + }) + child.once('exit', (code, signal) => resolveExit({ code, signal })) + }) + } finally { + process.off('SIGINT', forwardSigint) + process.off('SIGTERM', forwardSigterm) + } + + await outputDone + if (!logStream.destroyed) { + logStream.end() + } + await waitForClose(logStream) + if (spawnError) { + console.error('=== VITEST CHILD SPAWN FAILURE ===') + console.error(errorMessage(spawnError)) + reportLogPath(target.logPath) + return 1 + } + + const logWriteError = getWriteError() + if (logWriteError) { + console.error('=== VITEST LOG FAILURE (could not write the complete log) ===') + console.error(errorMessage(logWriteError)) + reportLogPath(target.logPath) + return 1 + } + + let scan + try { + scan = assertCleanVitestLogs([target.logPath]) + } catch (error) { + reportChildFailure(outcome) + console.error('=== VITEST LOG SCAN FAILURE ===') + console.error(errorMessage(error)) + reportLogPath(target.logPath) + return outcome.code === 0 && outcome.signal === null ? 1 : outcomeExitCode(outcome) + } + + if (outcome.code === 0 && outcome.signal === null && !scan.hasFailure) { + try { + rmSync(target.logPath, { force: true }) + if (target.tempDirectory) { + rmSync(target.tempDirectory, { recursive: true, force: true }) + } + } catch (error) { + console.error('=== VITEST GUARD CLEANUP FAILURE ===') + console.error(errorMessage(error)) + reportLogPath(target.logPath) + return 1 + } + return 0 + } + + reportChildFailure(outcome) + if (scan.hasFailure) { + console.error('=== ABSORBED WORKER-START SIGNATURE DETECTED ===') + if (outcome.code === 0 && outcome.signal === null) { + console.error('vitest exited 0 but the raw log contains a canonical worker-start failure signature.') + } + console.error(formatReport(scan)) + } + reportLogPath(target.logPath) + return outcomeExitCode(outcome) +} + +export async function runCli(argv) { + process.exitCode = await runGuardedVitest(argv) +} + +const isCli = process.argv[1] && fileURLToPath(import.meta.url) === resolve(process.argv[1]) +if (isCli) { + try { + await runCli(process.argv.slice(2)) + } catch (error) { + const message = error instanceof Error ? error.message : String(error) + console.error(`vitest guard failed: ${message}`) + process.exitCode = 1 + } +} diff --git a/tests/fixtures/vitest-guard/controlled-child.mjs b/tests/fixtures/vitest-guard/controlled-child.mjs new file mode 100644 index 00000000..75e20000 --- /dev/null +++ b/tests/fixtures/vitest-guard/controlled-child.mjs @@ -0,0 +1,27 @@ +import { rmSync } from 'node:fs' + +const stdout = process.env.VITEST_GUARD_FIXTURE_STDOUT ?? '' +const stderr = process.env.VITEST_GUARD_FIXTURE_STDERR ?? '' + +if (stdout) { + await new Promise((resolve, reject) => { + process.stdout.write(stdout, (error) => error ? reject(error) : resolve()) + }) +} + +if (stderr) { + await new Promise((resolve, reject) => { + process.stderr.write(stderr, (error) => error ? reject(error) : resolve()) + }) +} + +if (process.env.VITEST_GUARD_FIXTURE_DELETE_LOG === '1') { + rmSync(process.env.VITEST_GUARD_LOG_PATH, { force: true }) +} + +const signal = process.env.VITEST_GUARD_FIXTURE_SIGNAL +if (signal) { + process.kill(process.pid, signal) +} else { + process.exitCode = Number(process.env.VITEST_GUARD_FIXTURE_EXIT_CODE ?? '0') +} diff --git a/tests/fixtures/vitest-guard/delayed-output.mjs b/tests/fixtures/vitest-guard/delayed-output.mjs new file mode 100644 index 00000000..743ecd22 --- /dev/null +++ b/tests/fixtures/vitest-guard/delayed-output.mjs @@ -0,0 +1,3 @@ +process.stdout.write('STREAMED_LINE_ONE\n') +await new Promise((resolve) => setTimeout(resolve, 160)) +process.stdout.write('STREAMED_LINE_TWO\n') diff --git a/tests/fixtures/vitest-guard/echo-args.mjs b/tests/fixtures/vitest-guard/echo-args.mjs new file mode 100644 index 00000000..02519fea --- /dev/null +++ b/tests/fixtures/vitest-guard/echo-args.mjs @@ -0,0 +1 @@ +process.stdout.write(`FORWARDED_ARGS=${JSON.stringify(process.argv.slice(2))}\n`) diff --git a/tests/fixtures/vitest-guard/exercise-signal-forwarder.mjs b/tests/fixtures/vitest-guard/exercise-signal-forwarder.mjs new file mode 100644 index 00000000..989d0599 --- /dev/null +++ b/tests/fixtures/vitest-guard/exercise-signal-forwarder.mjs @@ -0,0 +1,38 @@ +// Deterministic, real-signal-free exercise of the wrapper's one-shot signal-forwarding latch +// (createSignalForwarder). Calling it twice synchronously reproduces the exact race the latch +// exists to close -- two deliveries arriving before Node would ever have a chance to update +// exitCode/signalCode -- without depending on real OS signal timing, which is a separate, +// necessarily best-effort concern covered by the process-level test in the .test.ts file. +import { createSignalForwarder } from '../../../scripts/run-guarded-vitest.mjs' + +function makeFakeChild(overrides = {}) { + const child = { + exitCode: null, + signalCode: null, + killCalls: [], + ...overrides, + } + child.kill = (signal) => { + child.killCalls.push(signal) + } + return child +} + +const alive = makeFakeChild() +const forwardSignal = createSignalForwarder(alive) + +const firstResult = forwardSignal('SIGTERM') +const secondResult = forwardSignal('SIGTERM') + +process.stdout.write(`FIRST_FORWARD_RESULT=${firstResult}\n`) +process.stdout.write(`SECOND_FORWARD_RESULT=${secondResult}\n`) +process.stdout.write(`KILL_CALL_COUNT=${alive.killCalls.length}\n`) +process.stdout.write(`KILL_CALLS=${JSON.stringify(alive.killCalls)}\n`) + +// A separate forwarder instance, so this exercises the exitCode guard itself rather than the +// latch: a child that has already exited must never be signaled, latch or no latch. +const alreadyExited = makeFakeChild({ exitCode: 0 }) +const exitedResult = createSignalForwarder(alreadyExited)('SIGTERM') + +process.stdout.write(`EXITED_CHILD_FORWARD_RESULT=${exitedResult}\n`) +process.stdout.write(`EXITED_CHILD_KILL_CALL_COUNT=${alreadyExited.killCalls.length}\n`) diff --git a/tests/fixtures/vitest-guard/signal-counter.mjs b/tests/fixtures/vitest-guard/signal-counter.mjs new file mode 100644 index 00000000..6989fd29 --- /dev/null +++ b/tests/fixtures/vitest-guard/signal-counter.mjs @@ -0,0 +1,26 @@ +// Stands in for Vitest to prove the wrapper delivers a terminating signal to the child at most +// once. Unlike controlled-child.mjs's VITEST_GUARD_FIXTURE_SIGNAL self-kill (which proves the +// wrapper *reports* a signal-terminated child correctly), this fixture stays alive after +// receiving a signal instead of dying from it, so a test can observe every delivery this process +// actually received rather than only the first one. +// +// Registering a listener for SIGTERM/SIGINT overrides Node's default (terminate the process), so +// this process keeps running across as many deliveries as arrive during the observation window +// below, then exits on its own -- the test never has to reach in and kill it itself. +let receivedCount = 0 + +function onSignal(signal) { + receivedCount += 1 + process.stdout.write(`SIGNAL_RECEIVED ${signal} count=${receivedCount}\n`) +} + +process.on('SIGTERM', () => onSignal('SIGTERM')) +process.on('SIGINT', () => onSignal('SIGINT')) + +process.stdout.write('SIGNAL_COUNTER_READY\n') + +// Long enough for a duplicate delivery to arrive if the wrapper's forwarding is buggy, short +// enough to keep the test fast. +setTimeout(() => { + process.exit(0) +}, 500) diff --git a/tests/unit/run-guarded-vitest.test.ts b/tests/unit/run-guarded-vitest.test.ts new file mode 100644 index 00000000..cba5a01b --- /dev/null +++ b/tests/unit/run-guarded-vitest.test.ts @@ -0,0 +1,380 @@ +import { spawn, spawnSync } from 'node:child_process' +import { existsSync, mkdtempSync, readFileSync, readdirSync, rmSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join, resolve } from 'node:path' + +import { describe, expect, it } from 'vitest' + +const runnerPath = resolve('scripts/run-guarded-vitest.mjs') +const controlledChildPath = resolve('tests/fixtures/vitest-guard/controlled-child.mjs') +const delayedOutputChildPath = resolve('tests/fixtures/vitest-guard/delayed-output.mjs') +const echoArgsChildPath = resolve('tests/fixtures/vitest-guard/echo-args.mjs') +const signalCounterChildPath = resolve('tests/fixtures/vitest-guard/signal-counter.mjs') +const exerciseSignalForwarderPath = resolve('tests/fixtures/vitest-guard/exercise-signal-forwarder.mjs') + +const CLEAN_OUTPUT = [ + ' RUN v4.1.5 /repo', + ' ✓ tests/unit/example.test.ts (1 test)', + ' Test Files 1 passed (1)', + ' Tests 1 passed (1)', + '', +].join('\n') + +function runGuard(args: string[], overrides: NodeJS.ProcessEnv = {}) { + const env: NodeJS.ProcessEnv = { + ...process.env, + VITEST_GUARD_EXEC_OVERRIDE: controlledChildPath, + ...overrides, + } + delete env.VITEST_GUARD_LOG_PATH + if (overrides.VITEST_GUARD_LOG_PATH !== undefined) { + env.VITEST_GUARD_LOG_PATH = overrides.VITEST_GUARD_LOG_PATH + } + + return spawnSync(process.execPath, [runnerPath, ...args], { + encoding: 'utf8', + env, + stdio: 'pipe', + }) +} + +describe('guarded vitest CLI', () => { + it('succeeds for clean output and removes its automatically-created log directory', () => { + const tempRoot = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-test-root-')) + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: CLEAN_OUTPUT, + TMPDIR: tempRoot, + TMP: tempRoot, + TEMP: tempRoot, + }) + + expect(result.status).toBe(0) + expect(result.stdout).toContain('Test Files 1 passed (1)') + expect(readdirSync(tempRoot)).toEqual([]) + } finally { + rmSync(tempRoot, { recursive: true, force: true }) + } + }) + + it('fails and retains the raw log when a green run absorbs a worker-start failure', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-signature-')) + const logPath = join(dir, 'green-with-worker-failure.log') + const signature = 'Failed to start forks worker' + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: `${signature}\n${CLEAN_OUTPUT}`, + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).not.toBe(0) + expect(result.stderr).toContain('ABSORBED WORKER-START SIGNATURE DETECTED') + expect(result.stderr).toContain(signature) + expect(existsSync(logPath)).toBe(true) + expect(readFileSync(logPath, 'utf8')).toContain(signature) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('fails for an absorbed forks-worker handshake timeout', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-timeout-')) + const logPath = join(dir, 'handshake-timeout.log') + const signature = 'Timeout waiting for worker to respond' + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDERR: `${signature}\n${CLEAN_OUTPUT}`, + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).not.toBe(0) + expect(result.stderr).toContain('ABSORBED WORKER-START SIGNATURE DETECTED') + expect(result.stderr).toContain(signature) + expect(readFileSync(logPath, 'utf8')).toContain(signature) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('preserves a clean child process failure exit code without claiming a signature', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-child-failure-')) + const logPath = join(dir, 'child-exit-3.log') + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: 'ordinary assertion failure\n', + VITEST_GUARD_FIXTURE_EXIT_CODE: '3', + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).toBe(3) + expect(result.stderr).toContain('CHILD PROCESS FAILURE (exit code 3)') + expect(result.stderr).not.toContain('ABSORBED WORKER-START SIGNATURE DETECTED') + expect(existsSync(logPath)).toBe(true) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('reports the child exit and absorbed signature as separate failure causes', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-double-failure-')) + const logPath = join(dir, 'child-and-signature.log') + const signature = 'Failed to start forks worker' + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: `${signature}\n`, + VITEST_GUARD_FIXTURE_EXIT_CODE: '4', + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).toBe(4) + expect(result.stderr).toContain('CHILD PROCESS FAILURE (exit code 4)') + expect(result.stderr).toContain('ABSORBED WORKER-START SIGNATURE DETECTED') + expect(result.stderr).toContain(signature) + expect(existsSync(logPath)).toBe(true) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('reports when the child process is terminated by a signal', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-signal-')) + const logPath = join(dir, 'signal.log') + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: 'child is about to terminate\n', + VITEST_GUARD_FIXTURE_SIGNAL: 'SIGTERM', + VITEST_GUARD_LOG_PATH: logPath, + }) + + // Windows has no POSIX signals: `child.kill('SIGTERM')` there terminates the process via + // TerminateProcess, so Node reports `signal: null` with a numeric exit code instead of a + // signal name. The wrapper's signal-reporting branch is never reached in that case, and it + // correctly falls through to its exit-code failure branch instead -- that is the wrapper + // behaving correctly, not a defect. Assert the platform-correct observable behavior on each + // OS rather than one POSIX-shaped assertion for both: termination must still be reported as + // a failure with the retained log path printed on every platform. Do not collapse this back + // into a single unconditional assertion -- that already hid this exact platform gap once. + expect(result.status).not.toBe(0) + if (process.platform === 'win32') { + expect(result.stderr).toMatch(/CHILD PROCESS FAILURE \(exit code \d+\)/) + } else { + expect(result.stderr).toContain('CHILD PROCESS FAILURE (signal SIGTERM)') + } + expect(result.stderr).toContain('Retained vitest log path:') + expect(existsSync(logPath)).toBe(true) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('forwards a signal to the child at most once, even when called twice before exitCode/signalCode could update', () => { + // Deterministic, no real OS signals or timing involved: exercises createSignalForwarder + // directly against a fake child via a subprocess, matching this file's established pattern + // of treating scripts/*.mjs as opaque CLIs rather than statically importing them into + // typechecked test code (see the sibling assert-clean-vitest-log.test.ts for the same + // rationale -- the repo's tsconfig has no allowJs). + const result = spawnSync(process.execPath, [exerciseSignalForwarderPath], { encoding: 'utf8' }) + + expect(result.status).toBe(0) + expect(result.stdout).toContain('FIRST_FORWARD_RESULT=true') + expect(result.stdout).toContain('SECOND_FORWARD_RESULT=false') + expect(result.stdout).toContain('KILL_CALL_COUNT=1') + expect(result.stdout).toContain('KILL_CALLS=["SIGTERM"]') + expect(result.stdout).toContain('EXITED_CHILD_FORWARD_RESULT=false') + expect(result.stdout).toContain('EXITED_CHILD_KILL_CALL_COUNT=0') + }) + + // POSIX only, deliberately, not a coverage gap: this end-to-end mechanism -- a target process + // catching a signal via `process.on('SIGTERM', ...)` instead of dying from it -- does not exist + // on Windows for either hop. `child.kill('SIGTERM')` there forcibly terminates the target + // (Node's own documented Windows behavior; there is no catchable delivery to bypass), so + // sending it to the wrapper never lets the wrapper's own handler run at all, and the wrapper + // forwarding a signal to the fixture would behave the same way -- there is no Windows-native + // "caught, stayed alive, logged it" outcome this test could assert instead, for any wrapper + // implementation, correct or buggy. Confirmed empirically: this test failed on both Windows CI + // lanes with zero deliveries observed, because the wrapper process was terminated before its + // own SIGTERM handler could run, not because forwarding was broken. The platform-independent + // proof of the actual fix (the one-shot latch itself, exercised as pure logic against a fake + // child, no real signal delivery involved) is the preceding test, which passes on every + // platform including both Windows lanes -- that is where the regression coverage that matters + // cross-platform lives; this test adds real-signal, real-process-group confirmation on the + // platforms where that confirmation is actually obtainable. + it.skipIf(process.platform === 'win32')('delivers exactly one real signal to a still-alive child when the wrapper itself is signaled', async () => { + const env: NodeJS.ProcessEnv = { + ...process.env, + VITEST_GUARD_EXEC_OVERRIDE: signalCounterChildPath, + } + delete env.VITEST_GUARD_LOG_PATH + + const wrapper = spawn(process.execPath, [runnerPath, 'run'], { + env, + stdio: ['ignore', 'pipe', 'pipe'], + }) + + let stdout = '' + const ready = new Promise((resolveReady) => { + wrapper.stdout.on('data', (chunk: Buffer) => { + stdout += chunk.toString('utf8') + if (stdout.includes('SIGNAL_COUNTER_READY')) { + resolveReady() + } + }) + }) + await ready + + wrapper.kill('SIGTERM') + + await new Promise((resolveClose) => { + wrapper.once('close', () => resolveClose()) + }) + + const deliveries = stdout.match(/SIGNAL_RECEIVED SIGTERM/g) ?? [] + expect(deliveries.length).toBe(1) + }) + + it('fails closed when the retained log disappears before scanning', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-missing-log-')) + const logPath = join(dir, 'deleted-before-scan.log') + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_DELETE_LOG: '1', + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).not.toBe(0) + expect(result.stderr).toContain('VITEST LOG SCAN FAILURE') + expect(result.stderr).toContain('Log file not found') + expect(result.stderr).toContain(logPath) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('does not false-positive on similar worker lifecycle wording', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-unrelated-')) + const logPath = join(dir, 'unrelated.log') + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: [ + 'restart a worker process gracefully', + 'Worker responded after a short delay', + CLEAN_OUTPUT, + ].join('\n'), + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).toBe(0) + expect(result.stderr).not.toContain('ABSORBED WORKER-START SIGNATURE DETECTED') + expect(existsSync(logPath)).toBe(false) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('forwards every argument verbatim without shell reinterpretation', () => { + const forwardedArgs = [ + 'run', + 'tests/unit/path with spaces.test.ts', + '--reporter=verbose output', + '--', + 'literal-$()-and-*', + ] + const result = runGuard(forwardedArgs, { + VITEST_GUARD_EXEC_OVERRIDE: echoArgsChildPath, + }) + + expect(result.status).toBe(0) + const encodedArgs = result.stdout + .split(/\r?\n/) + .find((line) => line.startsWith('FORWARDED_ARGS=')) + ?.slice('FORWARDED_ARGS='.length) + expect(encodedArgs).toBeDefined() + expect(JSON.parse(encodedArgs ?? 'null')).toEqual(forwardedArgs) + }) + + it('detects and retains a failure at a log path containing spaces and Unicode', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-unicode-')) + const logPath = join(dir, 'sub dir 名前', 'raw output α.log') + const signature = 'Failed to start forks worker' + + try { + const result = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: `${signature}\n`, + VITEST_GUARD_LOG_PATH: logPath, + }) + + expect(result.status).not.toBe(0) + expect(result.stderr).toContain(signature) + expect(result.stderr).toContain(logPath) + expect(readFileSync(logPath, 'utf8')).toContain(signature) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('deletes successful logs and retains failed logs under explicit paths', () => { + const dir = mkdtempSync(join(tmpdir(), 'madar-vitest-guard-retention-')) + const successfulLogPath = join(dir, 'successful.log') + const failedLogPath = join(dir, 'failed.log') + + try { + const successful = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: CLEAN_OUTPUT, + VITEST_GUARD_LOG_PATH: successfulLogPath, + }) + const failed = runGuard(['run'], { + VITEST_GUARD_FIXTURE_STDOUT: 'Failed to start forks worker\n', + VITEST_GUARD_LOG_PATH: failedLogPath, + }) + + expect(successful.status).toBe(0) + expect(existsSync(successfulLogPath)).toBe(false) + expect(failed.status).not.toBe(0) + expect(existsSync(failedLogPath)).toBe(true) + } finally { + rmSync(dir, { recursive: true, force: true }) + } + }) + + it('streams child output as it arrives instead of buffering until exit', async () => { + const env: NodeJS.ProcessEnv = { + ...process.env, + VITEST_GUARD_EXEC_OVERRIDE: delayedOutputChildPath, + } + delete env.VITEST_GUARD_LOG_PATH + + const child = spawn(process.execPath, [runnerPath, 'run'], { + env, + stdio: ['ignore', 'pipe', 'pipe'], + }) + const stdoutEvents: Array<{ at: number; text: string }> = [] + let stderr = '' + child.stdout.on('data', (chunk: Buffer) => { + stdoutEvents.push({ at: Date.now(), text: chunk.toString('utf8') }) + }) + child.stderr.on('data', (chunk: Buffer) => { + stderr += chunk.toString('utf8') + }) + + const exitCode = await new Promise((resolveExit, rejectSpawn) => { + child.once('error', rejectSpawn) + child.once('close', resolveExit) + }) + + expect(exitCode, stderr).toBe(0) + const first = stdoutEvents.find((event) => event.text.includes('STREAMED_LINE_ONE')) + const second = stdoutEvents.find((event) => event.text.includes('STREAMED_LINE_TWO')) + expect(first).toBeDefined() + expect(second).toBeDefined() + expect(stdoutEvents.length).toBeGreaterThanOrEqual(2) + expect((second?.at ?? 0) - (first?.at ?? 0)).toBeGreaterThanOrEqual(50) + }) +}) diff --git a/tests/unit/vitest-guard-policy.test.ts b/tests/unit/vitest-guard-policy.test.ts new file mode 100644 index 00000000..d0807747 --- /dev/null +++ b/tests/unit/vitest-guard-policy.test.ts @@ -0,0 +1,125 @@ +import { readFileSync, readdirSync } from 'node:fs' +import { resolve } from 'node:path' + +import { describe, expect, it } from 'vitest' +import { parse } from 'yaml' + +interface WorkflowStep { + env?: Record + if?: string + name?: string + run?: string + uses?: string + with?: Record +} + +interface Workflow { + jobs?: Record +} + +function readRepoFile(path: string): string { + return readFileSync(resolve(path), 'utf8') +} + +function parseWorkflow(path: string): Workflow { + return parse(readRepoFile(path)) as Workflow +} + +function workflowStep(path: string, jobName: string, stepName: string): WorkflowStep { + const step = parseWorkflow(path).jobs?.[jobName]?.steps?.find((candidate) => candidate.name === stepName) + if (!step) { + throw new Error(`Missing ${jobName} workflow step: ${stepName}`) + } + return step +} + +describe('guarded Vitest repository policy', () => { + it('guards both public complete-suite npm scripts', () => { + const packageJson = JSON.parse(readRepoFile('package.json')) as { + scripts?: Record + } + + expect(packageJson.scripts?.['test:run']).toContain('scripts/run-guarded-vitest.mjs') + expect(packageJson.scripts?.['test:coverage']).toContain('scripts/run-guarded-vitest.mjs') + expect(packageJson.scripts?.test).toBe('vitest') + }) + + it('imports the canonical scanner instead of duplicating its signature policy', () => { + const scannerSource = readRepoFile('.github/scripts/assert-clean-vitest-log.mjs') + const runnerSource = readRepoFile('scripts/run-guarded-vitest.mjs') + + expect(runnerSource).toContain("from '../.github/scripts/assert-clean-vitest-log.mjs'") + expect(runnerSource).toContain('assertCleanVitestLogs') + expect(runnerSource).toContain('formatReport') + expect(runnerSource).toContain('WORKER_FAILURE_SIGNATURES') + for (const signature of [ + 'Failed to start forks worker', + 'Timeout waiting for worker to respond', + ]) { + expect(scannerSource).toContain(signature) + expect(runnerSource).not.toContain(signature) + } + }) + + it('keeps CI complete-suite steps guarded and publishes only their failure logs', () => { + const testRun = workflowStep('.github/workflows/ci.yml', 'validate', 'Run tests') + const coverage = workflowStep('.github/workflows/ci.yml', 'validate', 'Run tests with coverage thresholds') + const upload = workflowStep('.github/workflows/ci.yml', 'validate', 'Upload raw vitest logs on failure') + + expect(testRun.run).toBe('npm run test:run') + expect(testRun.env?.VITEST_GUARD_LOG_PATH).toBe( + '${{ runner.temp }}/vitest-guard-test-run-${{ matrix.os }}-node${{ matrix.node-version }}.log', + ) + expect(coverage.run).toBe('npm run test:coverage') + expect(coverage.env?.VITEST_GUARD_LOG_PATH).toBe( + '${{ runner.temp }}/vitest-guard-test-coverage-${{ matrix.os }}-node${{ matrix.node-version }}.log', + ) + expect(upload.if).toBe('failure()') + expect(upload.uses).toBe('actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a') + expect(String(upload.with?.name)).toContain('github.run_id') + expect(String(upload.with?.name)).toContain('github.run_attempt') + expect(String(upload.with?.name)).toContain('matrix.os') + expect(String(upload.with?.name)).toContain('matrix.node-version') + expect(String(upload.with?.path)).toContain('vitest-guard-test-run-') + expect(String(upload.with?.path)).toContain('vitest-guard-test-coverage-') + expect(upload.with?.['if-no-files-found']).toBe('ignore') + expect(upload.with?.['retention-days']).toBe(7) + }) + + it('keeps stable release tests guarded and uploads the one possible failure log', () => { + const testRun = workflowStep('.github/workflows/release.yml', 'release', 'Run tests') + const upload = workflowStep('.github/workflows/release.yml', 'release', 'Upload raw vitest logs on failure') + + expect(testRun.run).toBe('npm run test:run') + expect(testRun.env?.VITEST_GUARD_LOG_PATH).toBe( + '${{ runner.temp }}/vitest-guard-test-run-ubuntu-latest-node20.log', + ) + expect(upload.if).toBe('failure()') + expect(upload.uses).toBe('actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a') + expect(String(upload.with?.name)).toContain('github.run_id') + expect(String(upload.with?.name)).toContain('github.run_attempt') + expect(upload.with?.path).toBe('${{ runner.temp }}/vitest-guard-test-run-ubuntu-latest-node20.log') + expect(upload.with?.['if-no-files-found']).toBe('ignore') + expect(upload.with?.['retention-days']).toBe(7) + }) + + it('keeps publish-next on its existing direct canonical scanner gate', () => { + expect(readRepoFile('.github/workflows/publish-next.yml')) + .toContain('.github/scripts/assert-clean-vitest-log.mjs') + }) + + it('contains no raw vitest run invocation in any workflow', () => { + const workflowDirectory = resolve('.github/workflows') + for (const filename of readdirSync(workflowDirectory).filter((name) => name.endsWith('.yml'))) { + expect(readFileSync(resolve(workflowDirectory, filename), 'utf8'), filename) + .not.toMatch(/\bvitest run\b/) + } + }) + + it('preserves the four-worker, no-retry Vitest configuration', () => { + const config = readRepoFile('vitest.config.ts') + + expect(config).toMatch(/\bmaxWorkers:\s*4\b/) + expect(config).not.toMatch(/\bretry\s*:/) + }) +})