Skip to content

Commit

Permalink
fixup! test_runner: add stack on unhandled rejections
Browse files Browse the repository at this point in the history
  • Loading branch information
atlowChemi committed Feb 14, 2024
1 parent 353b6b3 commit 759b0a2
Show file tree
Hide file tree
Showing 7 changed files with 47 additions and 43 deletions.
8 changes: 6 additions & 2 deletions lib/internal/test_runner/harness.js
Original file line number Diff line number Diff line change
Expand Up @@ -14,10 +14,12 @@ const {
codes: {
ERR_TEST_FAILURE,
},
inspectWithNoCustomRetry,
} = require('internal/errors');
const { exitCodes: { kGenericUserError } } = internalBinding('errors');

const { kEmptyObject } = require('internal/util');
const colors = require('internal/util/colors');
const { kCancelledByParent, Test, Suite } = require('internal/test_runner/test');
const {
parseCommandLine,
Expand Down Expand Up @@ -56,16 +58,18 @@ function createProcessEventHandler(eventName, rootTest) {
// 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;
const inspectOptions = { __proto__: null, colors: colors.shouldColorize(process.stdout), breakLength: Infinity };

if (test) {
msg = `Warning: Test "${test.name}" 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.\nStack: ${err.stack}`;
`triggered an ${eventName} event.\n${inspectWithNoCustomRetry(err, inspectOptions)}`;
} else {
msg = 'Warning: 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.\nStack: ${err.stack}`;
`triggered an ${eventName} event, caught by the test runner.\n` +
inspectWithNoCustomRetry(err, inspectOptions);
}

rootTest.diagnostic(msg);
Expand Down
12 changes: 6 additions & 6 deletions test/fixtures/test-runner/output/describe_it.snapshot
Original file line number Diff line number Diff line change
Expand Up @@ -693,12 +693,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.\\nStack: Error: rejected from unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nStack: Error: rejected from async unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nStack: Error: thrown from immediate throw fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nStack: Error: rejected from immediate reject fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):20)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nStack: Error [ERR_TEST_FAILURE]: callback invoked multiple times
# 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.\\nStack: Error: thrown from callback async throw after done\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nError: rejected from unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nError: rejected from async unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nError: thrown from immediate throw fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nError: rejected from immediate reject fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):20)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\n[Error [ERR_TEST_FAILURE]: callback invoked multiple times] { code: 'ERR_TEST_FAILURE', failureType: 'multipleCallbackInvocations', cause: 'callback invoked multiple times' }
# 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.\\nError: thrown from callback async throw after done\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/describe_it.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# tests 67
# suites 11
# pass 31
Expand Down
14 changes: 7 additions & 7 deletions test/fixtures/test-runner/output/junit_reporter.snapshot
Original file line number Diff line number Diff line change
Expand Up @@ -473,7 +473,7 @@ Error [ERR_TEST_FAILURE]: test could not be started because its parent finished
</failure>
</testcase>
<!-- 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.
Stack: Error: rejected from unhandled rejection fail
Error: rejected from unhandled rejection fail
*
*
*
Expand All @@ -482,7 +482,7 @@ Stack: Error: rejected from unhandled rejection fail
*
at async Test.processPendingSubtests (node:internal/test_runner/test:382:7) -->
<!-- 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.
Stack: Error: rejected from async unhandled rejection fail
Error: rejected from async unhandled rejection fail
*
*
*
Expand All @@ -491,21 +491,21 @@ Stack: Error: rejected from async unhandled rejection fail
*
at async Test.processPendingSubtests (node:internal/test_runner/test:382:7) -->
<!-- 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.
Stack: Error: uncaught from outside of a test
Error: uncaught from outside of a test
*
at process.processImmediate (node:internal/timers:478:21) -->
<!-- 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.
Stack: Error: thrown from immediate throw fail
Error: thrown from immediate throw fail
*
at process.processImmediate (node:internal/timers:478:21) -->
<!-- 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.
Stack: Error: rejected from immediate reject fail
Error: rejected from immediate reject fail
*
at process.processImmediate (node:internal/timers:478:21) -->
<!-- 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.
Stack: Error [ERR_TEST_FAILURE]: callback invoked multiple times -->
[Error [ERR_TEST_FAILURE]: callback invoked multiple times] { code: 'ERR_TEST_FAILURE', failureType: 'multipleCallbackInvocations', cause: 'callback invoked multiple times' } -->
<!-- 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.
Stack: Error: thrown from callback async throw after done
Error: thrown from callback async throw after done
*
at process.processImmediate (node:internal/timers:478:21) -->
<!-- tests 76 -->
Expand Down
14 changes: 7 additions & 7 deletions test/fixtures/test-runner/output/output.snapshot
Original file line number Diff line number Diff line change
Expand Up @@ -676,13 +676,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.\\nStack: Error: rejected from unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nStack: Error: rejected from async unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nStack: Error: uncaught from outside of a test\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):9)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nStack: Error: thrown from immediate throw fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nStack: Error: rejected from immediate reject fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):20)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nStack: Error [ERR_TEST_FAILURE]: callback invoked multiple times
# 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.\\nStack: Error: thrown from callback async throw after done\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nError: rejected from unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nError: rejected from async unhandled rejection fail\\n at TestContext.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):18)\\n at Test.runInAsyncScope (node:async_hooks:206:9)\\n at Test.run (node:internal/test_runner/test:641:25)\\n at Test.processPendingSubtests (node:internal/test_runner/test:382:18)\\n at Test.postRun (node:internal/test_runner/test:732:19)\\n at Test.run (node:internal/test_runner/test:690:12)\\n at async Test.processPendingSubtests (node:internal/test_runner/test:382:7)
# 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.\\nError: uncaught from outside of a test\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):9)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nError: thrown from immediate throw fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\nError: rejected from immediate reject fail\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):20)\\n at process.processImmediate (node:internal/timers:478:21)
# 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.\\n[Error [ERR_TEST_FAILURE]: callback invoked multiple times] { code: 'ERR_TEST_FAILURE', failureType: 'multipleCallbackInvocations', cause: 'callback invoked multiple times' }
# 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.\\nError: thrown from callback async throw after done\\n at Immediate.<anonymous> (/test/fixtures/test-runner/output/output.js:(LINE):11)\\n at process.processImmediate (node:internal/timers:478:21)
# tests 76
# suites 0
# pass 35
Expand Down
Loading

0 comments on commit 759b0a2

Please sign in to comment.