From 7b106eddca8cc16d0e9428d4bdf1d54bf8538bc8 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Fri, 4 Aug 2023 19:54:59 +0200 Subject: [PATCH 1/2] test: add expectSyncExitWithoutError() and expectSyncExit() utils These can be used to check the state and the output of a child process launched with `spawnSync()`. They log additional information about the child process when the check fails to facilitate debugging test failures. --- test/common/README.md | 38 +++++++++++++++++ test/common/child_process.js | 80 ++++++++++++++++++++++++++++++++++++ 2 files changed, 118 insertions(+) diff --git a/test/common/README.md b/test/common/README.md index db56e4744dd1b1..3d35edf5510186 100644 --- a/test/common/README.md +++ b/test/common/README.md @@ -6,6 +6,7 @@ This directory contains modules used to test the Node.js implementation. * [ArrayStream module](#arraystream-module) * [Benchmark module](#benchmark-module) +* [Child process module](#child-process-module) * [Common module API](#common-module-api) * [Countdown module](#countdown-module) * [CPU Profiler module](#cpu-profiler-module) @@ -35,6 +36,42 @@ The `benchmark` module is used by tests to run benchmarks. * `env` [\][] Environment variables to be applied during the run. +## Child Process Module + +The `child_process` module is used by tests that launch child processes. + +### `expectSyncExit(child, options)` + +Checks if a _synchronous_ child process runs in the way expected. If it does +not, print the stdout and stderr output from the child process and additional +information about it to the stderr of the current process before throwing +and error. This helps gathering more information about test failures +coming from child processes. + +* `child` [\][]: a `ChildProcess` instance + returned by `child_process.spawnSync()`. +* `options` [\][] + * `status` [\][] Expected `child.status` + * `signal` [\][] | `null` Expected `child.signal` + * `stderr` [\][] | [\][] | + [\][] Optional. If it's a string, check that the output + to the stderr of the child process is exactly the same as the string. If + it's a regular expression, check that the stderr matches it. If it's a + function, invoke it with the stderr output as a string and check + that it returns true. The function can just throw errors (e.g. assertion + errors) to provide more information if the check fails. + * `stdout` [\][] | [\][] | + [\][] Optional. Similar to `stderr` but for the stdout. + * `trim` [\][] Optional. Whether this method should trim + out the whitespace characters when checking `stderr` and `stdout` outputs. + Defaults to `false`. + +### `expectSyncExitWithoutError(child[, options])` + +Similar to `expectSyncExit()` with the `status` expected to be 0 and +`signal` expected to be `null`. Any other optional options are passed +into `expectSyncExit()`. + ## Common Module API The `common` module is used by tests for consistency across repeated @@ -1111,6 +1148,7 @@ See [the WPT tests README][] for details. []: https://developer.mozilla.org/en-US/docs/Web/API/ArrayBufferView []: https://nodejs.org/api/buffer.html#buffer_class_buffer []: https://developer.mozilla.org/en-US/docs/Web/API/BufferSource +[]: ../../doc/api/child_process.md#class-childprocess []: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Error []: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Function []: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Object diff --git a/test/common/child_process.js b/test/common/child_process.js index 799c963a7ed7dc..a53dddc19f3216 100644 --- a/test/common/child_process.js +++ b/test/common/child_process.js @@ -2,6 +2,7 @@ const assert = require('assert'); const common = require('./'); +const util = require('util'); // Workaround for Windows Server 2008R2 // When CMD is used to launch a process and CMD is killed too quickly, the @@ -41,9 +42,88 @@ function logAfterTime(time) { }, time); } +function checkOutput(str, check) { + if ((check instanceof RegExp && !check.test(str)) || + (typeof check === 'string' && check !== str)) { + return { passed: false, reason: `did not match ${util.inspect(check)}` }; + } + if (typeof check === 'function') { + try { + check(str); + } catch (error) { + return { + passed: false, + reason: `did not match expectation, checker throws:\n${util.inspect(error)}`, + }; + } + } + return { passed: true }; +} + +function expectSyncExit(child, { + status, + signal, + stderr: stderrCheck, + stdout: stdoutCheck, + trim = false, +}) { + const failures = []; + let stderrStr, stdoutStr; + if (status !== undefined && child.status !== status) { + failures.push(`- process terminated with status ${child.status}, expected ${status}`); + } + if (signal !== undefined && child.signal !== signal) { + failures.push(`- process terminated with signal ${child.signal}, expected ${signal}`); + } + + function logAndThrow() { + const tag = `[process ${child.pid}]:`; + console.error(`${tag} --- stderr ---`); + console.error(stderrStr === undefined ? child.stderr.toString() : stderrStr); + console.error(`${tag} --- stdout ---`); + console.error(stdoutStr === undefined ? child.stdout.toString() : stdoutStr); + console.error(`${tag} status = ${child.status}, signal = ${child.signal}`); + throw new Error(`${failures.join('\n')}`); + } + + // If status and signal are not matching expectations, fail early. + if (failures.length !== 0) { + logAndThrow(); + } + + if (stderrCheck !== undefined) { + stderrStr = child.stderr.toString(); + const { passed, reason } = checkOutput(trim ? stderrStr.trim() : stderrStr, stderrCheck); + if (!passed) { + failures.push(`- stderr ${reason}`); + } + } + if (stdoutCheck !== undefined) { + stdoutStr = child.stdout.toString(); + const { passed, reason } = checkOutput(trim ? stdoutStr.trim() : stdoutStr, stdoutCheck); + if (!passed) { + failures.push(`- stdout ${reason}`); + } + } + if (failures.length !== 0) { + logAndThrow(); + } + return { child, stderr: stderrStr, stdout: stdoutStr }; +} + +function expectSyncExitWithoutError(child, options) { + return expectSyncExit(child, { + status: 0, + signal: null, + ...options, + }); +} + module.exports = { cleanupStaleProcess, logAfterTime, kExpiringChildRunTime, kExpiringParentTimer, + expectSyncExit, + expectSyncExitWithoutError, }; From 930385293db796f5bf9039ef3cbf19bc77ba8e65 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Fri, 4 Aug 2023 19:58:32 +0200 Subject: [PATCH 2/2] test: use expectSyncExit{WithErrors} in snapshot tests ..and replace the similar code added for logging. --- test/parallel/test-snapshot-api.js | 18 +++-- test/parallel/test-snapshot-basic.js | 42 ++++------- test/parallel/test-snapshot-warning.js | 96 ++++++++++++-------------- 3 files changed, 69 insertions(+), 87 deletions(-) diff --git a/test/parallel/test-snapshot-api.js b/test/parallel/test-snapshot-api.js index 38b17add3db9c1..1068ae3b4c7b46 100644 --- a/test/parallel/test-snapshot-api.js +++ b/test/parallel/test-snapshot-api.js @@ -7,6 +7,7 @@ const assert = require('assert'); const { spawnSync } = require('child_process'); const tmpdir = require('../common/tmpdir'); const fixtures = require('../common/fixtures'); +const { expectSyncExitWithoutError } = require('../common/child_process'); const fs = require('fs'); const v8 = require('v8'); @@ -36,11 +37,8 @@ const entry = fixtures.path('snapshot', 'v8-startup-snapshot-api.js'); ], { cwd: tmpdir.path }); - if (child.status !== 0) { - console.log(child.stderr.toString()); - console.log(child.stdout.toString()); - assert.strictEqual(child.status, 0); - } + + expectSyncExitWithoutError(child); const stats = fs.statSync(tmpdir.resolve('snapshot.blob')); assert(stats.isFile()); } @@ -58,9 +56,9 @@ const entry = fixtures.path('snapshot', 'v8-startup-snapshot-api.js'); } }); - const stdout = child.stdout.toString().trim(); - const stderr = child.stderr.toString().trim(); - assert.strictEqual(stderr, 'Reading book1.en_US.txt'); - assert.strictEqual(stdout, 'This is book1.en_US.txt'); - assert.strictEqual(child.status, 0); + expectSyncExitWithoutError(child, { + stderr: 'Reading book1.en_US.txt', + stdout: 'This is book1.en_US.txt', + trim: true + }); } diff --git a/test/parallel/test-snapshot-basic.js b/test/parallel/test-snapshot-basic.js index 6f1d3c21ae1772..cd87caa3fcbce3 100644 --- a/test/parallel/test-snapshot-basic.js +++ b/test/parallel/test-snapshot-basic.js @@ -8,6 +8,7 @@ const assert = require('assert'); const { spawnSync } = require('child_process'); const tmpdir = require('../common/tmpdir'); const fixtures = require('../common/fixtures'); +const { expectSyncExitWithoutError, expectSyncExit } = require('../common/child_process'); const fs = require('fs'); tmpdir.refresh(); @@ -15,7 +16,7 @@ tmpdir.refresh(); let snapshotScript = 'node:embedded_snapshot_main'; if (!process.config.variables.node_use_node_snapshot) { // Check that Node.js built without an embedded snapshot - // exits with 1 when node:embedded_snapshot_main is specified + // exits with 9 when node:embedded_snapshot_main is specified // as snapshot entry point. const child = spawnSync(process.execPath, [ '--build-snapshot', @@ -24,10 +25,11 @@ if (!process.config.variables.node_use_node_snapshot) { cwd: tmpdir.path }); - assert.match( - child.stderr.toString(), - /Node\.js was built without embedded snapshot/); - assert.strictEqual(child.status, 9); + expectSyncExit(child, { + status: 9, + signal: null, + stderr: /Node\.js was built without embedded snapshot/ + }); snapshotScript = fixtures.path('empty.js'); } @@ -41,12 +43,7 @@ if (!process.config.variables.node_use_node_snapshot) { ], { cwd: tmpdir.path }); - if (child.status !== 0) { - console.log(child.stderr.toString()); - console.log(child.stdout.toString()); - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + expectSyncExitWithoutError(child); const stats = fs.statSync(tmpdir.resolve('snapshot.blob')); assert(stats.isFile()); } @@ -63,12 +60,7 @@ const blobPath = tmpdir.resolve('my-snapshot.blob'); ], { cwd: tmpdir.path }); - if (child.status !== 0) { - console.log(child.stderr.toString()); - console.log(child.stdout.toString()); - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + expectSyncExitWithoutError(child); const stats = fs.statSync(blobPath); assert(stats.isFile()); } @@ -82,13 +74,7 @@ const blobPath = tmpdir.resolve('my-snapshot.blob'); ], { cwd: tmpdir.path }); - - if (child.status !== 0) { - console.log(child.stderr.toString()); - console.log(child.stdout.toString()); - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + expectSyncExitWithoutError(child); assert(child.stdout.toString().includes('--help')); } @@ -105,7 +91,9 @@ const blobPath = tmpdir.resolve('my-snapshot.blob'); }); // Check that it is a noop. - assert.strictEqual(child.stdout.toString().trim(), ''); - assert.strictEqual(child.stderr.toString().trim(), ''); - assert.strictEqual(child.status, 0); + expectSyncExitWithoutError(child, { + stderr: '', + stdout: '', + trim: true + }); } diff --git a/test/parallel/test-snapshot-warning.js b/test/parallel/test-snapshot-warning.js index 2ca87f1ef5f055..444f65af0b8b35 100644 --- a/test/parallel/test-snapshot-warning.js +++ b/test/parallel/test-snapshot-warning.js @@ -10,6 +10,7 @@ const assert = require('assert'); const { spawnSync } = require('child_process'); const tmpdir = require('../common/tmpdir'); const fixtures = require('../common/fixtures'); +const { expectSyncExitWithoutError } = require('../common/child_process'); const fs = require('fs'); const warningScript = fixtures.path('snapshot', 'warning.js'); @@ -27,12 +28,7 @@ tmpdir.refresh(); ], { cwd: tmpdir.path }); - console.log('[stderr]:', child.stderr.toString()); - console.log('[stdout]:', child.stdout.toString()); - if (child.status !== 0) { - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + expectSyncExitWithoutError(child); const stats = fs.statSync(blobPath); assert(stats.isFile()); @@ -43,14 +39,14 @@ tmpdir.refresh(); ], { cwd: tmpdir.path }); - console.log('[stderr]:', child.stderr.toString()); - console.log('[stdout]:', child.stdout.toString()); - if (child.status !== 0) { - console.log(child.signal); - assert.strictEqual(child.status, 0); - } - const match = child.stderr.toString().match(/Warning: test warning/g); - assert.strictEqual(match.length, 1); + expectSyncExitWithoutError(child, { + stderr(output) { + const match = output.match(/Warning: test warning/g); + assert.strictEqual(match.length, 1); + return true; + } + }); + } tmpdir.refresh(); @@ -65,18 +61,17 @@ tmpdir.refresh(); ], { cwd: tmpdir.path }); - console.log('[stderr]:', child.stderr.toString()); - console.log('[stdout]:', child.stdout.toString()); - if (child.status !== 0) { - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + expectSyncExitWithoutError(child, { + stderr(output) { + let match = output.match(/Warning: test warning/g); + assert.strictEqual(match.length, 1); + match = output.match(/Use `node --trace-warnings/g); + assert.strictEqual(match.length, 1); + return true; + } + }); const stats = fs.statSync(blobPath); assert(stats.isFile()); - let match = child.stderr.toString().match(/Warning: test warning/g); - assert.strictEqual(match.length, 1); - match = child.stderr.toString().match(/Use `node --trace-warnings/g); - assert.strictEqual(match.length, 1); child = spawnSync(process.execPath, [ '--snapshot-blob', @@ -85,17 +80,17 @@ tmpdir.refresh(); ], { cwd: tmpdir.path }); - console.log('[stderr]:', child.stderr.toString()); - console.log('[stdout]:', child.stdout.toString()); - if (child.status !== 0) { - console.log(child.signal); - assert.strictEqual(child.status, 0); - } - // Warnings should not be handled more than once. - match = child.stderr.toString().match(/Warning: test warning/g); - assert.strictEqual(match.length, 1); - match = child.stderr.toString().match(/Use `node --trace-warnings/g); - assert.strictEqual(match.length, 1); + + expectSyncExitWithoutError(child, { + stderr(output) { + // Warnings should not be handled more than once. + let match = output.match(/Warning: test warning/g); + assert.strictEqual(match.length, 1); + match = output.match(/Use `node --trace-warnings/g); + assert.strictEqual(match.length, 1); + return true; + } + }); } tmpdir.refresh(); @@ -114,25 +109,26 @@ tmpdir.refresh(); ], { cwd: tmpdir.path }); - console.log('[stderr]:', child.stderr.toString()); - console.log('[stdout]:', child.stdout.toString()); - if (child.status !== 0) { - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + + expectSyncExitWithoutError(child, { + stderr(output) { + assert.doesNotMatch(output, /Warning: test warning/); + } + }); + const stats = fs.statSync(blobPath); assert(stats.isFile()); + const warnings1 = fs.readFileSync(warningFile1, 'utf8'); console.log(warningFile1, ':', warnings1); let match = warnings1.match(/Warning: test warning/g); assert.strictEqual(match.length, 1); match = warnings1.match(/Use `node --trace-warnings/g); assert.strictEqual(match.length, 1); - assert.doesNotMatch(child.stderr.toString(), /Warning: test warning/); - fs.rmSync(warningFile1, { maxRetries: 3, recursive: false, force: true }); + child = spawnSync(process.execPath, [ '--snapshot-blob', blobPath, @@ -142,12 +138,13 @@ tmpdir.refresh(); ], { cwd: tmpdir.path }); - console.log('[stderr]:', child.stderr.toString()); - console.log('[stdout]:', child.stdout.toString()); - if (child.status !== 0) { - console.log(child.signal); - assert.strictEqual(child.status, 0); - } + + expectSyncExitWithoutError(child, { + stderr(output) { + assert.doesNotMatch(output, /Warning: test warning/); + return true; + } + }); assert(!fs.existsSync(warningFile1)); const warnings2 = fs.readFileSync(warningFile2, 'utf8'); @@ -156,5 +153,4 @@ tmpdir.refresh(); assert.strictEqual(match.length, 1); match = warnings2.match(/Use `node --trace-warnings/g); assert.strictEqual(match.length, 1); - assert.doesNotMatch(child.stderr.toString(), /Warning: test warning/); }