From e78d65c1f1d3244ad1a8a998b989dd826aab93f9 Mon Sep 17 00:00:00 2001 From: Mark Wubben Date: Sun, 12 Nov 2023 21:52:37 +0100 Subject: [PATCH 1/4] Don't force-exit after tests have completed Fixes #1718. With worker threads, this seems to stop AVA from detecting that the thread has exited, causing a hang. Also remove flush logic implemented in #1722. Let's hope that current Node.js versions are better at flushing IPC before exiting. --- lib/fork.js | 5 ---- lib/reporters/default.js | 6 +++++ lib/worker/base.js | 57 +++++++++++++++++++++++----------------- lib/worker/channel.cjs | 16 ----------- 4 files changed, 39 insertions(+), 45 deletions(-) diff --git a/lib/fork.js b/lib/fork.js index 5ddf294e8..8317774ff 100644 --- a/lib/fork.js +++ b/lib/fork.js @@ -122,11 +122,6 @@ export default function loadFork(file, options, execArgv = process.execArgv) { break; } - case 'ping': { - send({type: 'pong'}); - break; - } - default: { emitStateChange(message.ava); } diff --git a/lib/reporters/default.js b/lib/reporters/default.js index df9dc68e1..b6f8df7de 100644 --- a/lib/reporters/default.js +++ b/lib/reporters/default.js @@ -240,6 +240,12 @@ export default class Reporter { break; } + case 'exit-failed': { + this.write(colors.error(`${figures.cross} Failed to exit when running ${this.relativeFile(event.testFile)}`)); + + break; + } + case 'hook-finished': { if (event.logs.length > 0) { this.lineWriter.writeLine(` ${this.prefixTitle(event.testFile, event.title)}`); diff --git a/lib/worker/base.js b/lib/worker/base.js index fd1fee372..d897e7cda 100644 --- a/lib/worker/base.js +++ b/lib/worker/base.js @@ -23,35 +23,42 @@ import {isRunningInThread, isRunningInChildProcess} from './utils.cjs'; const currentlyUnhandled = setUpCurrentlyUnhandled(); let runner; +let failedToExit = false; + +const expectExit = code => { + // Set the exit code, which is just handy. + process.exitCode = code; + + // Note that this timer is unreferenced. It should not keep the event loop + // open. However if after a second the process is still running, assume + // something is keeping the event loop busy. Exit forcibly but try to convey + // the reason to the main process. + nowAndTimers.setTimeout(() => { + failedToExit = true; + channel.send({type: 'exit-failed', code}); + process.exit(1); + }, 1000).unref(); +}; + // Override process.exit with an undetectable replacement // to report when it is called from a test (which it should never be). -const {apply} = Reflect; -const realExit = process.exit; - -async function exit(code, forceSync = false) { - const flushing = channel.flush(); - if (!forceSync) { - await flushing; +const handleProcessExit = (target, thisArg, args) => { + if (!failedToExit) { + const error = new Error('Unexpected process.exit()'); + Error.captureStackTrace(error, handleProcessExit); + channel.send({type: 'process-exit', stack: error.stack}); } - apply(realExit, process, [code]); -} - -const handleProcessExit = (fn, receiver, args) => { - const error = new Error('Unexpected process.exit()'); - Error.captureStackTrace(error, handleProcessExit); - channel.send({type: 'process-exit', stack: error.stack}); - // Make sure to extract the code only from `args` rather than e.g. `Array.prototype`. // This level of paranoia is usually unwarranted, but we're dealing with test code // that has already colored outside the lines. const code = args.length > 0 ? args[0] : undefined; // Force a synchronous exit as guaranteed by the real process.exit(). - exit(code, true); + target.call(thisArg, code); }; -process.exit = new Proxy(realExit, { +process.exit = new Proxy(process.exit, { apply: handleProcessExit, }); @@ -101,7 +108,7 @@ const run = async options => { runner.on('error', error => { channel.send({type: 'internal-error', err: serializeError(error)}); - exit(1); + expectExit(1); }); runner.on('finish', async () => { @@ -112,7 +119,7 @@ const run = async options => { } } catch (error) { channel.send({type: 'internal-error', err: serializeError(error)}); - exit(1); + expectExit(1); return; } @@ -120,22 +127,24 @@ const run = async options => { await Promise.all(sharedWorkerTeardowns.map(fn => fn())); } catch (error) { channel.send({type: 'uncaught-exception', err: serializeError(error)}); - exit(1); + expectExit(1); return; } nowAndTimers.setImmediate(() => { + let exitCode = 0; for (const rejection of currentlyUnhandled()) { channel.send({type: 'unhandled-rejection', err: serializeError(rejection.reason, {testFile: options.file})}); + exitCode = 1; } - exit(0); + expectExit(exitCode); }); }); process.on('uncaughtException', error => { channel.send({type: 'uncaught-exception', err: serializeError(error, {testFile: options.file})}); - exit(1); + expectExit(1); }); // Store value to prevent required modules from modifying it. @@ -248,11 +257,11 @@ const run = async options => { channel.unref(); } else { channel.send({type: 'missing-ava-import'}); - exit(1); + expectExit(1); } } catch (error) { channel.send({type: 'uncaught-exception', err: serializeError(error, {testFile: options.file})}); - exit(1); + expectExit(1); } }; diff --git a/lib/worker/channel.cjs b/lib/worker/channel.cjs index 2479f4bcb..3f11a973a 100644 --- a/lib/worker/channel.cjs +++ b/lib/worker/channel.cjs @@ -110,22 +110,6 @@ exports.peerFailed = selectAvaMessage(handle.channel, 'peer-failed'); exports.send = handle.send.bind(handle); exports.unref = handle.unref.bind(handle); -let pendingPings = Promise.resolve(); -async function flush() { - handle.ref(); - const promise = pendingPings.then(async () => { - handle.send({type: 'ping'}); - await selectAvaMessage(handle.channel, 'pong'); - if (promise === pendingPings) { - handle.unref(); - } - }); - pendingPings = promise; - await promise; -} - -exports.flush = flush; - let channelCounter = 0; let messageCounter = 0; From ba50194fb770c37f0b24580f35251bcfac305a39 Mon Sep 17 00:00:00 2001 From: Mark Wubben Date: Sun, 26 Nov 2023 21:55:03 +0100 Subject: [PATCH 2/4] fixup! Don't force-exit after tests have completed --- lib/reporters/default.js | 7 +----- lib/run-status.js | 4 +++ lib/worker/base.js | 53 +++++++++++++++------------------------- 3 files changed, 25 insertions(+), 39 deletions(-) diff --git a/lib/reporters/default.js b/lib/reporters/default.js index b6f8df7de..a70f24e4e 100644 --- a/lib/reporters/default.js +++ b/lib/reporters/default.js @@ -240,12 +240,6 @@ export default class Reporter { break; } - case 'exit-failed': { - this.write(colors.error(`${figures.cross} Failed to exit when running ${this.relativeFile(event.testFile)}`)); - - break; - } - case 'hook-finished': { if (event.logs.length > 0) { this.lineWriter.writeLine(` ${this.prefixTitle(event.testFile, event.title)}`); @@ -369,6 +363,7 @@ export default class Reporter { writePendingTests(evt) { for (const [file, testsInFile] of evt.pendingTests) { if (testsInFile.size === 0) { + this.lineWriter.writeLine(`Failed to exit when running ${this.relativeFile(file)}\n`); continue; } diff --git a/lib/run-status.js b/lib/run-status.js index f58c9bcbc..cd80fc847 100644 --- a/lib/run-status.js +++ b/lib/run-status.js @@ -193,6 +193,10 @@ export default class RunStatus extends Emittery { case 'worker-finished': { stats.finishedWorkers++; + if (this.pendingTests.get(event.testFile)?.size === 0) { + this.pendingTests.delete(event.testFile); + } + break; } diff --git a/lib/worker/base.js b/lib/worker/base.js index d897e7cda..d5a483af5 100644 --- a/lib/worker/base.js +++ b/lib/worker/base.js @@ -23,39 +23,23 @@ import {isRunningInThread, isRunningInChildProcess} from './utils.cjs'; const currentlyUnhandled = setUpCurrentlyUnhandled(); let runner; -let failedToExit = false; - -const expectExit = code => { - // Set the exit code, which is just handy. - process.exitCode = code; - - // Note that this timer is unreferenced. It should not keep the event loop - // open. However if after a second the process is still running, assume - // something is keeping the event loop busy. Exit forcibly but try to convey - // the reason to the main process. - nowAndTimers.setTimeout(() => { - failedToExit = true; - channel.send({type: 'exit-failed', code}); - process.exit(1); - }, 1000).unref(); +let forcingExit = false; + +const forceExit = () => { + forcingExit = true; + process.exit(1); }; // Override process.exit with an undetectable replacement // to report when it is called from a test (which it should never be). const handleProcessExit = (target, thisArg, args) => { - if (!failedToExit) { + if (!forcingExit) { const error = new Error('Unexpected process.exit()'); Error.captureStackTrace(error, handleProcessExit); channel.send({type: 'process-exit', stack: error.stack}); } - // Make sure to extract the code only from `args` rather than e.g. `Array.prototype`. - // This level of paranoia is usually unwarranted, but we're dealing with test code - // that has already colored outside the lines. - const code = args.length > 0 ? args[0] : undefined; - - // Force a synchronous exit as guaranteed by the real process.exit(). - target.call(thisArg, code); + target.apply(thisArg, args); }; process.exit = new Proxy(process.exit, { @@ -108,7 +92,7 @@ const run = async options => { runner.on('error', error => { channel.send({type: 'internal-error', err: serializeError(error)}); - expectExit(1); + forceExit(); }); runner.on('finish', async () => { @@ -119,7 +103,7 @@ const run = async options => { } } catch (error) { channel.send({type: 'internal-error', err: serializeError(error)}); - expectExit(1); + forceExit(); return; } @@ -127,24 +111,27 @@ const run = async options => { await Promise.all(sharedWorkerTeardowns.map(fn => fn())); } catch (error) { channel.send({type: 'uncaught-exception', err: serializeError(error)}); - expectExit(1); + forceExit(); return; } nowAndTimers.setImmediate(() => { - let exitCode = 0; - for (const rejection of currentlyUnhandled()) { + const unhandled = currentlyUnhandled(); + if (unhandled.length === 0) { + return; + } + + for (const rejection of unhandled) { channel.send({type: 'unhandled-rejection', err: serializeError(rejection.reason, {testFile: options.file})}); - exitCode = 1; } - expectExit(exitCode); + forceExit(); }); }); process.on('uncaughtException', error => { channel.send({type: 'uncaught-exception', err: serializeError(error, {testFile: options.file})}); - expectExit(1); + forceExit(); }); // Store value to prevent required modules from modifying it. @@ -257,11 +244,11 @@ const run = async options => { channel.unref(); } else { channel.send({type: 'missing-ava-import'}); - expectExit(1); + forceExit(); } } catch (error) { channel.send({type: 'uncaught-exception', err: serializeError(error, {testFile: options.file})}); - expectExit(1); + forceExit(); } }; From 210eb95a608a7063dff872e54b0227f96cb7ad72 Mon Sep 17 00:00:00 2001 From: Mark Wubben Date: Sun, 26 Nov 2023 21:59:05 +0100 Subject: [PATCH 3/4] fixup! fixup! Don't force-exit after tests have completed --- test-tap/reporters/default.regular.v18.log | 2 ++ test-tap/reporters/default.regular.v20.log | 2 ++ test-tap/reporters/default.regular.v21.log | 2 ++ test-tap/reporters/tap.regular.v18.log | 4 +++- test-tap/reporters/tap.regular.v20.log | 4 +++- test-tap/reporters/tap.regular.v21.log | 4 +++- 6 files changed, 15 insertions(+), 3 deletions(-) diff --git a/test-tap/reporters/default.regular.v18.log b/test-tap/reporters/default.regular.v18.log index 49148cd43..c65476560 100644 --- a/test-tap/reporters/default.regular.v18.log +++ b/test-tap/reporters/default.regular.v18.log @@ -114,6 +114,8 @@ null +---tty-stream-chunk-separator + ✘ unhandled-rejection.cjs exited with a non-zero exit code: 1 ---tty-stream-chunk-separator ─ diff --git a/test-tap/reporters/default.regular.v20.log b/test-tap/reporters/default.regular.v20.log index 49148cd43..c65476560 100644 --- a/test-tap/reporters/default.regular.v20.log +++ b/test-tap/reporters/default.regular.v20.log @@ -114,6 +114,8 @@ null +---tty-stream-chunk-separator + ✘ unhandled-rejection.cjs exited with a non-zero exit code: 1 ---tty-stream-chunk-separator ─ diff --git a/test-tap/reporters/default.regular.v21.log b/test-tap/reporters/default.regular.v21.log index 49148cd43..c65476560 100644 --- a/test-tap/reporters/default.regular.v21.log +++ b/test-tap/reporters/default.regular.v21.log @@ -114,6 +114,8 @@ null +---tty-stream-chunk-separator + ✘ unhandled-rejection.cjs exited with a non-zero exit code: 1 ---tty-stream-chunk-separator ─ diff --git a/test-tap/reporters/tap.regular.v18.log b/test-tap/reporters/tap.regular.v18.log index bf22b1c7f..7686951e4 100644 --- a/test-tap/reporters/tap.regular.v18.log +++ b/test-tap/reporters/tap.regular.v18.log @@ -246,11 +246,13 @@ not ok 27 - unhandled-rejection formatted: 'null' ... ---tty-stream-chunk-separator +not ok 28 - unhandled-rejection.cjs exited with a non-zero exit code: 1 +---tty-stream-chunk-separator 1..21 # tests 20 # pass 6 # skip 1 -# fail 20 +# fail 21 ---tty-stream-chunk-separator diff --git a/test-tap/reporters/tap.regular.v20.log b/test-tap/reporters/tap.regular.v20.log index bf22b1c7f..7686951e4 100644 --- a/test-tap/reporters/tap.regular.v20.log +++ b/test-tap/reporters/tap.regular.v20.log @@ -246,11 +246,13 @@ not ok 27 - unhandled-rejection formatted: 'null' ... ---tty-stream-chunk-separator +not ok 28 - unhandled-rejection.cjs exited with a non-zero exit code: 1 +---tty-stream-chunk-separator 1..21 # tests 20 # pass 6 # skip 1 -# fail 20 +# fail 21 ---tty-stream-chunk-separator diff --git a/test-tap/reporters/tap.regular.v21.log b/test-tap/reporters/tap.regular.v21.log index bf22b1c7f..7686951e4 100644 --- a/test-tap/reporters/tap.regular.v21.log +++ b/test-tap/reporters/tap.regular.v21.log @@ -246,11 +246,13 @@ not ok 27 - unhandled-rejection formatted: 'null' ... ---tty-stream-chunk-separator +not ok 28 - unhandled-rejection.cjs exited with a non-zero exit code: 1 +---tty-stream-chunk-separator 1..21 # tests 20 # pass 6 # skip 1 -# fail 20 +# fail 21 ---tty-stream-chunk-separator From 4210433bcb1ef8d5ed591d5b3ebbadbc63c042c3 Mon Sep 17 00:00:00 2001 From: Mark Wubben Date: Sun, 3 Dec 2023 22:05:12 +0100 Subject: [PATCH 4/4] Fix external assertions tests for Node.js 21 The assertion message is different, which requires more creativity with the snapshots. --- test/external-assertions/snapshots/test.js.md | 193 +++++++++++++++++- .../snapshots/test.js.snap | Bin 328 -> 441 bytes test/external-assertions/test.js | 38 +++- 3 files changed, 221 insertions(+), 10 deletions(-) diff --git a/test/external-assertions/snapshots/test.js.md b/test/external-assertions/snapshots/test.js.md index 5db2b6acb..27ee77b13 100644 --- a/test/external-assertions/snapshots/test.js.md +++ b/test/external-assertions/snapshots/test.js.md @@ -4,7 +4,7 @@ The actual snapshot is saved in `test.js.snap`. Generated by [AVA](https://avajs.dev). -## node assertion +## node assertion (node.js v18) > Snapshot 1 @@ -46,7 +46,196 @@ Generated by [AVA](https://avajs.dev). ␊ 2 tests failed` -## expect error +## expect error (node.js v18) + +> Snapshot 1 + + `␊ + ✘ [fail]: test Assertion failed␊ + ✘ [fail]: test async Assertion failed␊ + β”€βŠ + ␊ + test␊ + ␊ + Assertion failed: ␊ + ␊ + expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + ␊ + Error: expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + ␊ + ␊ + ␊ + test async␊ + ␊ + Assertion failed: ␊ + ␊ + expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + ␊ + Error: expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + at ---␊ + at ---␊ + ␊ + β”€βŠ + ␊ + 2 tests failed` + +## node assertion (node.js v20) + +> Snapshot 1 + + `␊ + ✘ [fail]: test Assertion failed␊ + ✘ [fail]: test async Assertion failed␊ + β”€βŠ + ␊ + test␊ + ␊ + Assertion failed: ␊ + ␊ + false == true␊ + ␊ + AssertionError [ERR_ASSERTION]: false == true␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + ␊ + ␊ + ␊ + test async␊ + ␊ + Assertion failed: ␊ + ␊ + false == true␊ + ␊ + AssertionError [ERR_ASSERTION]: false == true␊ + at ---␊ + at ---␊ + ␊ + β”€βŠ + ␊ + 2 tests failed` + +## expect error (node.js v20) + +> Snapshot 1 + + `␊ + ✘ [fail]: test Assertion failed␊ + ✘ [fail]: test async Assertion failed␊ + β”€βŠ + ␊ + test␊ + ␊ + Assertion failed: ␊ + ␊ + expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + ␊ + Error: expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + ␊ + ␊ + ␊ + test async␊ + ␊ + Assertion failed: ␊ + ␊ + expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + ␊ + Error: expect(received).toBeTruthy()␊ + ␊ + Received: false␊ + at ---␊ + at ---␊ + ␊ + β”€βŠ + ␊ + 2 tests failed` + +## node assertion (node.js v21) + +> Snapshot 1 + + `␊ + ✘ [fail]: test Assertion failed␊ + ✘ [fail]: test async Assertion failed␊ + β”€βŠ + ␊ + test␊ + ␊ + Assertion failed: ␊ + ␊ + The expression evaluated to a falsy value:␊ + ␊ + assert(false)␊ + ␊ + AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:␊ + ␊ + assert(false)␊ + ␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + at ---␊ + ␊ + ␊ + ␊ + test async␊ + ␊ + Assertion failed: ␊ + ␊ + false == true␊ + ␊ + AssertionError [ERR_ASSERTION]: false == true␊ + at ---␊ + at ---␊ + ␊ + β”€βŠ + ␊ + 2 tests failed` + +## expect error (node.js v21) > Snapshot 1 diff --git a/test/external-assertions/snapshots/test.js.snap b/test/external-assertions/snapshots/test.js.snap index f9f9d3962e0458f7c30cafb7e4b7b3565e4c78c5..9e22a8fa3329dde379bc8e2829c2c18d22d71e8f 100644 GIT binary patch literal 441 zcmV;q0Y?5oRzV{5rbZ}8fyGSW=CU0pp zSysA_znCda@SO8NvTq>H{_OZ?>+bDefZ^>_HSbz+{>poq=;f1 zA0|9RU{a!>h$mpHdG$_0T03(hnXsW8aFUPHFl5B8%O5+Xy^=W z&!V{J0ih&lexIhQ80Kl1oFqZ6^7+BCK#SCOS>b`I_E{_u8Vw*Z!Ub7N2ri)8^8K4; zyWR3T7gv`(Z)pSQ!3bQ}{kMrVZ)?{37MlBUx2_)|vuo!p9N>6}0Rif3){szf7f3j& zY=?x|lWlXVF(>F+sXf%&*jn6h zk9HPPryq+500000000A9n3j~2pPXIXv?#SCvm_@qFE2kORUxssIJKxGGe0l0I4`lF zI3vHLxN%`hN@7W3B;#df26hGzU}R+wWIDpgrJ(R=&J2a$gKEitD!Rl(L)p`@rZ6-AkAQBi)8LbPj8 zP`qPsuxn6=r@tT2PE-vFV31g%psTA(Hx3ufTM)kwfaegQYXo*kG1OXU { - const result = await t.throwsAsync(fixture(['assert-failure.js'])); - t.snapshot(result.stdout.replaceAll('\r', '').replaceAll(/\/{3}/g, '//').replaceAll(/at.*\n/g, 'at ---\n')); -}); +const snapshotStdout = (t, stdout) => { + const normalized = stdout + .replaceAll('\r', '') + .replaceAll(/\/{3}/g, '//') + .replaceAll(/(\b)at.*\n/g, '$1at ---\n'); + + t.log(process.versions.node.split('.')[0]); + t.snapshot(normalized); +}; + +const major = process.versions.node.split('.')[0]; + +for (const version of ['18', '20', '21']) { + // Tests need to be declared for all versions, so that snapshots can be + // updated by running `npx test-ava -u test/external-assertions/test.js` for + // each supported version. However only the tests for the current version + // can run, so skip the others. + const declare = version === major ? test : test.skip; + + declare(`node assertion (node.js v${version})`, async t => { + const result = await t.throwsAsync(fixture(['assert-failure.js'])); + snapshotStdout(t, result.stdout); + }); -test('expect error ', async t => { - const result = await t.throwsAsync(fixture(['expect-failure.js'])); - t.snapshot(result.stdout.replaceAll('\r', '').replaceAll(/\/{3}/g, '//').replaceAll(/at.*\n/g, 'at ---\n')); -}); + declare(`expect error (node.js v${version})`, async t => { + const result = await t.throwsAsync(fixture(['expect-failure.js'])); + snapshotStdout(t, result.stdout); + }); +}