diff --git a/lib/internal/test_runner/harness.js b/lib/internal/test_runner/harness.js index 5f43e846f29585..3a00e5a3fcceab 100644 --- a/lib/internal/test_runner/harness.js +++ b/lib/internal/test_runner/harness.js @@ -10,6 +10,7 @@ const { createHook, executionAsyncId, } = require('async_hooks'); +const { relative } = require('path'); const { codes: { ERR_TEST_FAILURE, @@ -52,19 +53,26 @@ function createProcessEventHandler(eventName, rootTest) { throw err; } - // Check if this error is coming from a test. If it is, fail the test. - if (!test || test.finished) { + // Check if this error is coming from a test or test hook. If it is, fail the test. + if (!test || test.finished || test.hookType) { // If the test is already finished or the resource that created the error // is not mapped to a Test, report this as a top level diagnostic. let msg; if (test) { - msg = `Warning: Test "${test.name}" generated asynchronous ` + + const name = test.hookType ? `Test hook "${test.hookType}"` : `Test "${test.name}"`; + let locInfo = ''; + if (test.loc) { + const relPath = relative(process.cwd(), test.loc.file); + locInfo = ` at ${relPath}:${test.loc.line}:${test.loc.column}`; + } + + msg = `Error: ${name}${locInfo} generated asynchronous ` + 'activity after the test ended. This activity created the error ' + `"${err}" and would have caused the test to fail, but instead ` + `triggered an ${eventName} event.`; } else { - msg = 'Warning: A resource generated asynchronous activity after ' + + msg = 'Error: A resource generated asynchronous activity after ' + `the test ended. This activity created the error "${err}" which ` + `triggered an ${eventName} event, caught by the test runner.`; } diff --git a/test/fixtures/test-runner/async-error-in-test-hook.mjs b/test/fixtures/test-runner/async-error-in-test-hook.mjs new file mode 100644 index 00000000000000..5dca1ada75dada --- /dev/null +++ b/test/fixtures/test-runner/async-error-in-test-hook.mjs @@ -0,0 +1,27 @@ +import { after, afterEach, before, beforeEach, test } from 'node:test' + +before(() => { + setTimeout(() => { + throw new Error('before') + }, 100) +}) + +beforeEach(() => { + setTimeout(() => { + throw new Error('beforeEach') + }, 100) +}) + +after(() => { + setTimeout(() => { + throw new Error('after') + }, 100) +}) + +afterEach(() => { + setTimeout(() => { + throw new Error('afterEach') + }, 100) +}) + +test('ok', () => {}) diff --git a/test/fixtures/test-runner/output/describe_it.snapshot b/test/fixtures/test-runner/output/describe_it.snapshot index f6fed1a481908b..e9ff58e7beb0f9 100644 --- a/test/fixtures/test-runner/output/describe_it.snapshot +++ b/test/fixtures/test-runner/output/describe_it.snapshot @@ -691,12 +691,12 @@ not ok 58 - invalid subtest fail * ... 1..58 -# Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. -# Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. -# Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "unhandled rejection - passes but warns" at test/fixtures/test-runner/output/describe_it.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "async unhandled rejection - passes but warns" at test/fixtures/test-runner/output/describe_it.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "immediate throw - passes but warns" at test/fixtures/test-runner/output/describe_it.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "immediate reject - passes but warns" at test/fixtures/test-runner/output/describe_it.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "callback called twice in different ticks" at test/fixtures/test-runner/output/describe_it.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "callback async throw after done" at test/fixtures/test-runner/output/describe_it.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. # tests 67 # suites 11 # pass 31 diff --git a/test/fixtures/test-runner/output/junit_reporter.snapshot b/test/fixtures/test-runner/output/junit_reporter.snapshot index f29f72e6ddb2ed..d244e7dd594bb3 100644 --- a/test/fixtures/test-runner/output/junit_reporter.snapshot +++ b/test/fixtures/test-runner/output/junit_reporter.snapshot @@ -514,13 +514,13 @@ Error [ERR_TEST_FAILURE]: test could not be started because its parent finished } - - - - - - - + + + + + + + diff --git a/test/fixtures/test-runner/output/output.snapshot b/test/fixtures/test-runner/output/output.snapshot index 905acaa498bffb..0acb6573bc6710 100644 --- a/test/fixtures/test-runner/output/output.snapshot +++ b/test/fixtures/test-runner/output/output.snapshot @@ -711,13 +711,13 @@ not ok 62 - invalid subtest fail * ... 1..62 -# Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. -# Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. -# Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. -# Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "async unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. +# Error: Test "immediate throw - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "immediate reject - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "callback called twice in different ticks" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "callback async throw after done" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. # tests 76 # suites 0 # pass 35 diff --git a/test/fixtures/test-runner/output/output_cli.snapshot b/test/fixtures/test-runner/output/output_cli.snapshot index 37c85137e4eb7f..d04dc0a0a905ad 100644 --- a/test/fixtures/test-runner/output/output_cli.snapshot +++ b/test/fixtures/test-runner/output/output_cli.snapshot @@ -710,13 +710,13 @@ not ok 62 - invalid subtest fail stack: |- * ... -# Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. -# Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. -# Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. -# Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. -# Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "async unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. +# Error: Test "immediate throw - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "immediate reject - passes but warns" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. +# Error: Test "callback called twice in different ticks" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. +# Error: Test "callback async throw after done" at test/fixtures/test-runner/output/output.js:(LINE):1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. # Subtest: last test ok 63 - last test --- diff --git a/test/fixtures/test-runner/output/spec_reporter.snapshot b/test/fixtures/test-runner/output/spec_reporter.snapshot index 8162dafcdc0350..f37d7f35b8a7d6 100644 --- a/test/fixtures/test-runner/output/spec_reporter.snapshot +++ b/test/fixtures/test-runner/output/spec_reporter.snapshot @@ -297,13 +297,13 @@ invalid subtest fail (*ms) 'test could not be started because its parent finished' - Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. - Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. - Warning: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. - Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. - Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. - Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. - Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. + Error: Test "unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:72:1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. + Error: Test "async unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:76:1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. + Error: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. + Error: Test "immediate throw - passes but warns" at test/fixtures/test-runner/output/output.js:80:1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. + Error: Test "immediate reject - passes but warns" at test/fixtures/test-runner/output/output.js:86:1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. + Error: Test "callback called twice in different ticks" at test/fixtures/test-runner/output/output.js:251:1 generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. + Error: Test "callback async throw after done" at test/fixtures/test-runner/output/output.js:269:1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. tests 76 suites 0 pass 35 diff --git a/test/fixtures/test-runner/output/spec_reporter_cli.snapshot b/test/fixtures/test-runner/output/spec_reporter_cli.snapshot index 9386a6db82753f..d8648bfe03a8be 100644 --- a/test/fixtures/test-runner/output/spec_reporter_cli.snapshot +++ b/test/fixtures/test-runner/output/spec_reporter_cli.snapshot @@ -297,13 +297,13 @@ invalid subtest fail (*ms) 'test could not be started because its parent finished' - Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. - Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. - Warning: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. - Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. - Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. - Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. - Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. + Error: Test "unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:72:1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. + Error: Test "async unhandled rejection - passes but warns" at test/fixtures/test-runner/output/output.js:76:1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. + Error: A resource generated asynchronous activity after the test ended. This activity created the error "Error: uncaught from outside of a test" which triggered an uncaughtException event, caught by the test runner. + Error: Test "immediate throw - passes but warns" at test/fixtures/test-runner/output/output.js:80:1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. + Error: Test "immediate reject - passes but warns" at test/fixtures/test-runner/output/output.js:86:1 generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. + Error: Test "callback called twice in different ticks" at test/fixtures/test-runner/output/output.js:251:1 generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. + Error: Test "callback async throw after done" at test/fixtures/test-runner/output/output.js:269:1 generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. tests 76 suites 0 pass 35 diff --git a/test/parallel/test-runner-extraneous-async-activity.js b/test/parallel/test-runner-extraneous-async-activity.js index a95925dbb75414..68db109b292f15 100644 --- a/test/parallel/test-runner-extraneous-async-activity.js +++ b/test/parallel/test-runner-extraneous-async-activity.js @@ -10,7 +10,7 @@ const { spawnSync } = require('child_process'); fixtures.path('test-runner', 'extraneous_set_immediate_async.mjs'), ]); const stdout = child.stdout.toString(); - assert.match(stdout, /^# Warning: Test "extraneous async activity test" generated asynchronous activity after the test ended/m); + assert.match(stdout, /^# Error: Test "extraneous async activity test" at .+extraneous_set_immediate_async\.mjs:3:1 generated asynchronous activity after the test ended/m); assert.match(stdout, /^# pass 1/m); assert.match(stdout, /^# fail 1$/m); assert.match(stdout, /^# cancelled 0$/m); @@ -24,7 +24,24 @@ const { spawnSync } = require('child_process'); fixtures.path('test-runner', 'extraneous_set_timeout_async.mjs'), ]); const stdout = child.stdout.toString(); - assert.match(stdout, /^# Warning: Test "extraneous async activity test" generated asynchronous activity after the test ended/m); + assert.match(stdout, /^# Error: Test "extraneous async activity test" at .+extraneous_set_timeout_async\.mjs:3:1 generated asynchronous activity after the test ended/m); + assert.match(stdout, /^# pass 1$/m); + assert.match(stdout, /^# fail 1$/m); + assert.match(stdout, /^# cancelled 0$/m); + assert.strictEqual(child.status, 1); + assert.strictEqual(child.signal, null); +} + +{ + const child = spawnSync(process.execPath, [ + '--test', + fixtures.path('test-runner', 'async-error-in-test-hook.mjs'), + ]); + const stdout = child.stdout.toString(); + assert.match(stdout, /^# Error: Test hook "before" at .+async-error-in-test-hook\.mjs:3:1 generated asynchronous activity after the test ended/m); + assert.match(stdout, /^# Error: Test hook "beforeEach" at .+async-error-in-test-hook\.mjs:9:1 generated asynchronous activity after the test ended/m); + assert.match(stdout, /^# Error: Test hook "after" at .+async-error-in-test-hook\.mjs:15:1 generated asynchronous activity after the test ended/m); + assert.match(stdout, /^# Error: Test hook "afterEach" at .+async-error-in-test-hook\.mjs:21:1 generated asynchronous activity after the test ended/m); assert.match(stdout, /^# pass 1$/m); assert.match(stdout, /^# fail 1$/m); assert.match(stdout, /^# cancelled 0$/m); diff --git a/test/parallel/test-runner-output.mjs b/test/parallel/test-runner-output.mjs index abc3d7c97b4879..df1067ec04a4e0 100644 --- a/test/parallel/test-runner-output.mjs +++ b/test/parallel/test-runner-output.mjs @@ -70,11 +70,13 @@ const specTransform = snapshot.transform( replaceSpecDuration, snapshot.replaceWindowsLineEndings, snapshot.replaceStackTrace, + snapshot.replaceWindowsPaths, ); const junitTransform = snapshot.transform( replaceJunitDuration, snapshot.replaceWindowsLineEndings, snapshot.replaceStackTrace, + snapshot.replaceWindowsPaths, ); const lcovTransform = snapshot.transform( snapshot.replaceWindowsLineEndings,