Skip to content

Commit 4763c82

Browse files
committed
test: fix test runner does not print error cause
1 parent 142d6af commit 4763c82

7 files changed

+368
-22
lines changed

lib/internal/test_runner/reporter/tap.js

+27-8
Original file line numberDiff line numberDiff line change
@@ -3,22 +3,32 @@ const {
33
ArrayPrototypeForEach,
44
ArrayPrototypeJoin,
55
ArrayPrototypePush,
6+
ArrayPrototypeSome,
67
NumberPrototypeToFixed,
78
ObjectEntries,
89
RegExpPrototypeSymbolReplace,
910
SafeMap,
11+
StringPrototypeRepeat,
1012
StringPrototypeReplaceAll,
1113
StringPrototypeSplit,
12-
StringPrototypeRepeat,
14+
StringPrototypeStartsWith,
1315
} = primordials;
1416
const { inspectWithNoCustomRetry } = require('internal/errors');
1517
const { isError, kEmptyObject } = require('internal/util');
18+
const { inspect } = require('internal/util/inspect');
1619
const { relative } = require('path');
1720
const kDefaultIndent = ' '; // 4 spaces
18-
const kFrameStartRegExp = /^ {4}at /;
21+
const kFrameStartRegExp = /[{}]/;
1922
const kLineBreakRegExp = /\n|\r\n/;
2023
const kDefaultTAPVersion = 13;
2124
const inspectOptions = { colors: false, breakLength: Infinity };
25+
const keywords = [
26+
'...',
27+
'failureType',
28+
'cause',
29+
'code',
30+
'Error',
31+
];
2232
let testModule; // Lazy loaded due to circular dependency.
2333

2434
function lazyLoadTest() {
@@ -209,7 +219,11 @@ function jsToYaml(indent, name, value) {
209219
// If the ERR_TEST_FAILURE came from an error provided by user code,
210220
// then try to unwrap the original error message and stack.
211221
if (code === 'ERR_TEST_FAILURE' && kUnwrapErrors.has(failureType)) {
212-
errStack = cause?.stack ?? errStack;
222+
if (cause?.cause) {
223+
errStack = inspect(cause);
224+
} else {
225+
errStack = cause?.stack ?? errStack;
226+
}
213227
errCode = cause?.code ?? errCode;
214228
errName = cause?.name ?? errName;
215229
if (isAssertionLike(cause)) {
@@ -246,13 +260,18 @@ function jsToYaml(indent, name, value) {
246260
ArrayPrototypeForEach(
247261
StringPrototypeSplit(errStack, kLineBreakRegExp),
248262
(frame) => {
249-
const processed = RegExpPrototypeSymbolReplace(
263+
const processed = tapEscape(RegExpPrototypeSymbolReplace(
250264
kFrameStartRegExp,
251-
frame,
265+
ArrayPrototypeJoin(
266+
StringPrototypeSplit(frame, ' at'),
267+
'',
268+
),
252269
'',
253-
);
254-
255-
if (processed.length > 0 && processed.length !== frame.length) {
270+
));
271+
const trimmedProcessed = processed.trim();
272+
if (trimmedProcessed.length > 0 && processed !== kDefaultIndent && (processed.length !== frame.length ||
273+
StringPrototypeStartsWith(trimmedProcessed, '[cause]')) &&
274+
!ArrayPrototypeSome(keywords, (str) => StringPrototypeStartsWith(processed, str))) {
256275
ArrayPrototypePush(frames, processed);
257276
}
258277
},

test/message/test_runner_describe_it.out

+3-3
Original file line numberDiff line numberDiff line change
@@ -118,9 +118,9 @@ not ok 14 - async assertion fail
118118
failureType: 'testCodeFailure'
119119
error: |-
120120
Expected values to be strictly equal:
121-
121+
122122
true !== false
123-
123+
124124
code: 'ERR_ASSERTION'
125125
name: 'AssertionError'
126126
expected: false
@@ -563,7 +563,7 @@ not ok 56 - describe async throw fails
563563
error: 'test timed out after 5ms'
564564
code: 'ERR_TEST_FAILURE'
565565
stack: |-
566-
async Promise.all (index 0)
566+
async Promise.all (index 0)
567567
...
568568
# Subtest: timed out callback test
569569
not ok 2 - timed out callback test

test/message/test_runner_output.js

+28
Original file line numberDiff line numberDiff line change
@@ -389,3 +389,31 @@ test('unfinished test with unhandledRejection', async () => {
389389
setImmediate(() => {
390390
throw new Error('uncaught from outside of a test');
391391
});
392+
393+
test('should print error cause', () => {
394+
Error.stackTraceLimit = 4;
395+
throw new Error('foo', { cause: new Error('bar') });
396+
});
397+
398+
test('should print error cause for nested errors', () => {
399+
throw new Error('a', { cause: new Error('b', { cause:
400+
new Error('c', { cause: new Error('d', { cause: new Error('e') }) }) }) });
401+
});
402+
403+
test('should handle cycles in error', () => {
404+
const outer = new Error('b', { cause: null });
405+
outer.cause = new Error('c', { cause: new Error('d', { cause: outer }) });
406+
throw outer;
407+
});
408+
409+
test('should handle primitive, undefined and null cause', () => {
410+
test('primitive cause', () => {
411+
throw new Error('foo', { cause: 'something went wrong' });
412+
});
413+
test('undefined cause', () => {
414+
throw new Error('foo', { cause: undefined });
415+
});
416+
test('null cause', () => {
417+
throw new Error('foo', { cause: null });
418+
});
419+
});

test/message/test_runner_output.out

+114-4
Original file line numberDiff line numberDiff line change
@@ -624,8 +624,118 @@ not ok 64 - unfinished test with unhandledRejection
624624
*
625625
*
626626
...
627+
# Subtest: should print error cause
628+
not ok 65 - should print error cause
629+
---
630+
duration_ms: *
631+
failureType: 'testCodeFailure'
632+
error: 'foo'
633+
code: 'ERR_TEST_FAILURE'
634+
stack: |-
635+
*
636+
*
637+
*
638+
*
639+
[cause]: Error: bar
640+
*
641+
*
642+
*
643+
*
644+
...
645+
# Subtest: should print error cause for nested errors
646+
not ok 66 - should print error cause for nested errors
647+
---
648+
duration_ms: *
649+
failureType: 'testCodeFailure'
650+
error: 'a'
651+
code: 'ERR_TEST_FAILURE'
652+
stack: |-
653+
*
654+
*
655+
*
656+
*
657+
[cause]: Error: b
658+
*
659+
*
660+
*
661+
*
662+
[cause]: Error: c
663+
*
664+
*
665+
*
666+
*
667+
[cause]: [Error]
668+
...
669+
# Subtest: should handle cycles in error
670+
not ok 67 - should handle cycles in error
671+
---
672+
duration_ms: *
673+
failureType: 'testCodeFailure'
674+
error: 'b'
675+
code: 'ERR_TEST_FAILURE'
676+
stack: |-
677+
*
678+
*
679+
*
680+
*
681+
[cause]: Error: c
682+
*
683+
*
684+
*
685+
*
686+
[cause]: Error: d
687+
*
688+
*
689+
*
690+
*
691+
[cause]: [Circular *1]
692+
...
693+
# Subtest: should handle primitive, undefined and null cause
694+
# Subtest: primitive cause
695+
not ok 1 - primitive cause
696+
---
697+
duration_ms: *
698+
failureType: 'testCodeFailure'
699+
error: 'foo'
700+
code: 'ERR_TEST_FAILURE'
701+
stack: |-
702+
*
703+
*
704+
*
705+
*
706+
[cause]: 'something went wrong'
707+
...
708+
# Subtest: undefined cause
709+
not ok 2 - undefined cause
710+
---
711+
duration_ms: *
712+
failureType: 'testCodeFailure'
713+
error: 'foo'
714+
code: 'ERR_TEST_FAILURE'
715+
stack: |-
716+
*
717+
*
718+
*
719+
*
720+
...
721+
# Subtest: null cause
722+
not ok 3 - null cause
723+
---
724+
duration_ms: *
725+
failureType: 'cancelledByParent'
726+
error: 'test did not finish before its parent and was cancelled'
727+
code: 'ERR_TEST_FAILURE'
728+
...
729+
1..3
730+
not ok 68 - should handle primitive, undefined and null cause
731+
---
732+
duration_ms: *
733+
failureType: 'subtestsFailed'
734+
error: '3 subtests failed'
735+
code: 'ERR_TEST_FAILURE'
736+
...
627737
# Subtest: invalid subtest fail
628-
not ok 65 - invalid subtest fail
738+
not ok 69 - invalid subtest fail
629739
---
630740
duration_ms: *
631741
failureType: 'parentAlreadyFinished'
@@ -634,17 +744,17 @@ not ok 65 - invalid subtest fail
634744
stack: |-
635745
*
636746
...
637-
1..65
747+
1..69
638748
# 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.
639749
# 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.
640750
# 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.
641751
# 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.
642752
# 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.
643753
# 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.
644754
# 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.
645-
# tests 65
755+
# tests 69
646756
# pass 27
647-
# fail 21
757+
# fail 25
648758
# cancelled 2
649759
# skipped 10
650760
# todo 5

test/message/test_runner_output_cli.out

+114-4
Original file line numberDiff line numberDiff line change
@@ -624,8 +624,118 @@ not ok 64 - unfinished test with unhandledRejection
624624
*
625625
*
626626
...
627+
# Subtest: should print error cause
628+
not ok 65 - should print error cause
629+
---
630+
duration_ms: *
631+
failureType: 'testCodeFailure'
632+
error: 'foo'
633+
code: 'ERR_TEST_FAILURE'
634+
stack: |-
635+
*
636+
*
637+
*
638+
*
639+
[cause]: Error: bar
640+
*
641+
*
642+
*
643+
*
644+
...
645+
# Subtest: should print error cause for nested errors
646+
not ok 66 - should print error cause for nested errors
647+
---
648+
duration_ms: *
649+
failureType: 'testCodeFailure'
650+
error: 'a'
651+
code: 'ERR_TEST_FAILURE'
652+
stack: |-
653+
*
654+
*
655+
*
656+
*
657+
[cause]: Error: b
658+
*
659+
*
660+
*
661+
*
662+
[cause]: Error: c
663+
*
664+
*
665+
*
666+
*
667+
[cause]: [Error]
668+
...
669+
# Subtest: should handle cycles in error
670+
not ok 67 - should handle cycles in error
671+
---
672+
duration_ms: *
673+
failureType: 'testCodeFailure'
674+
error: 'b'
675+
code: 'ERR_TEST_FAILURE'
676+
stack: |-
677+
*
678+
*
679+
*
680+
*
681+
[cause]: Error: c
682+
*
683+
*
684+
*
685+
*
686+
[cause]: Error: d
687+
*
688+
*
689+
*
690+
*
691+
[cause]: [Circular *1]
692+
...
693+
# Subtest: should handle primitive, undefined and null cause
694+
# Subtest: primitive cause
695+
not ok 1 - primitive cause
696+
---
697+
duration_ms: *
698+
failureType: 'testCodeFailure'
699+
error: 'foo'
700+
code: 'ERR_TEST_FAILURE'
701+
stack: |-
702+
*
703+
*
704+
*
705+
*
706+
[cause]: 'something went wrong'
707+
...
708+
# Subtest: undefined cause
709+
not ok 2 - undefined cause
710+
---
711+
duration_ms: *
712+
failureType: 'testCodeFailure'
713+
error: 'foo'
714+
code: 'ERR_TEST_FAILURE'
715+
stack: |-
716+
*
717+
*
718+
*
719+
*
720+
...
721+
# Subtest: null cause
722+
not ok 3 - null cause
723+
---
724+
duration_ms: *
725+
failureType: 'cancelledByParent'
726+
error: 'test did not finish before its parent and was cancelled'
727+
code: 'ERR_TEST_FAILURE'
728+
...
729+
1..3
730+
not ok 68 - should handle primitive, undefined and null cause
731+
---
732+
duration_ms: *
733+
failureType: 'subtestsFailed'
734+
error: '3 subtests failed'
735+
code: 'ERR_TEST_FAILURE'
736+
...
627737
# Subtest: invalid subtest fail
628-
not ok 65 - invalid subtest fail
738+
not ok 69 - invalid subtest fail
629739
---
630740
duration_ms: *
631741
failureType: 'parentAlreadyFinished'
@@ -641,10 +751,10 @@ not ok 65 - invalid subtest fail
641751
# 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.
642752
# 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.
643753
# 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.
644-
1..65
645-
# tests 65
754+
1..69
755+
# tests 69
646756
# pass 27
647-
# fail 21
757+
# fail 25
648758
# cancelled 2
649759
# skipped 10
650760
# todo 5

0 commit comments

Comments
 (0)