test: fix test runner does not print error cause

Author: pulkit-30

lib/internal/test_runner/reporter/tap.js

@@ -10,10 +10,12 @@ const {
   StringPrototypeReplaceAll,
   StringPrototypeSplit,
   StringPrototypeRepeat,
+  StringPrototypeStartsWith
 } = primordials;
 const { inspectWithNoCustomRetry } = require('internal/errors');
 const { isError, kEmptyObject } = require('internal/util');
 const { relative } = require('path');
+const util = require('util');
 const kDefaultIndent = '    '; // 4 spaces
 const kFrameStartRegExp = /^ {4}at /;
 const kLineBreakRegExp = /\n|\r\n/;
@@ -234,9 +236,27 @@ function jsToYaml(indent, name, value) {
       }
     }
 
-    if (typeof errStack === 'string') {
-      const frames = [];
+    const frames = [];
 
+    if (cause?.cause) {
+      const errCause = util.inspect(cause).split('\n').slice(1)
+                      .filter((line) => !StringPrototypeStartsWith(line.trim(), '...') && line)
+                      .join('\n');
+      ArrayPrototypeForEach(
+        StringPrototypeSplit(errCause, kLineBreakRegExp),
+        (frame) => {
+          const processed = RegExpPrototypeSymbolReplace(
+            kFrameStartRegExp,
+            frame,
+            ''
+          );
+
+          if (processed.length > 0) {
+            ArrayPrototypePush(frames, processed);
+          }
+        }
+      );
+    } else if (typeof errStack === 'string') {
       ArrayPrototypeForEach(
         StringPrototypeSplit(errStack, kLineBreakRegExp),
         (frame) => {
@@ -251,13 +271,13 @@ function jsToYaml(indent, name, value) {
           }
         }
       );
+    }
 
-      if (frames.length > 0) {
-        const frameDelimiter = `\n${indent}    `;
+    if (frames.length > 0) {
+      const frameDelimiter = `\n${indent}    `;
 
-        result += `${indent}  stack: |-${frameDelimiter}`;
-        result += `${ArrayPrototypeJoin(frames, frameDelimiter)}\n`;
-      }
+      result += `${indent}  stack: |-${frameDelimiter}`;
+      result += `${ArrayPrototypeJoin(frames, frameDelimiter)}\n`;
     }
   }
 

test/message/test_runner_describe_it.out

@@ -113,9 +113,9 @@ not ok 13 - async assertion fail
   failureType: 'testCodeFailure'
   error: |-
     Expected values to be strictly equal:
-    
+
     true !== false
-    
+
   code: 'ERR_ASSERTION'
   expected: false
   actual: true
@@ -403,6 +403,10 @@ not ok 48 - callback called twice in future tick
   code: 'ERR_TEST_FAILURE'
   stack: |-
     *
+    *
+    *
+    *
+    *
   ...
 # Subtest: callback async throw
 not ok 49 - callback async throw

test/message/test_runner_output.js

@@ -383,3 +383,17 @@ test('unfinished test with unhandledRejection', async () => {
     setTimeout(() => Promise.reject(new Error('bar')));
   });
 });
+
+test('should print error cause', () => {
+  throw new Error('foo', {cause: new Error('bar')});
+});
+
+test('should print error cause for nested errors', () => {
+  throw new Error('a', { cause: new Error('b', { cause: new Error('c', { cause: new Error('d', { cause: new Error('e') }) }) }) })
+});
+
+test("should handle cycles in error", () => {
+  const outer = new Error('b', { cause: null });
+  outer.cause = new Error('c', { cause: new Error('d', { cause: outer }) });
+  throw outer;
+});

test/message/test_runner_output.out

@@ -447,6 +447,10 @@ not ok 50 - callback called twice in future tick
   code: 'ERR_TEST_FAILURE'
   stack: |-
     *
+    *
+    *
+    *
+    *
   ...
 # Subtest: callback async throw
 not ok 51 - callback async throw
@@ -620,8 +624,78 @@ not ok 64 - unfinished test with unhandledRejection
     *
     *
   ...
+# Subtest: should print error cause
+not ok 65 - should print error cause
+  ---
+  duration_ms: *
+  failureType: 'testCodeFailure'
+  error: 'foo'
+  code: 'ERR_TEST_FAILURE'
+  stack: |-
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+  ...
+# Subtest: should print error cause for nested errors
+not ok 66 - should print error cause for nested errors
+  ---
+  duration_ms: *
+  failureType: 'testCodeFailure'
+  error: 'a'
+  code: 'ERR_TEST_FAILURE'
+  stack: |-
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+  ...
+# Subtest: should handle cycles in error
+not ok 67 - should handle cycles in error
+  ---
+  duration_ms: *
+  failureType: 'testCodeFailure'
+  error: 'b'
+  code: 'ERR_TEST_FAILURE'
+  stack: |-
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+    *
+  ...
 # Subtest: invalid subtest fail
-not ok 65 - invalid subtest fail
+not ok 68 - invalid subtest fail
   ---
   duration_ms: *
   failureType: 'parentAlreadyFinished'
@@ -630,16 +704,16 @@ not ok 65 - invalid subtest fail
   stack: |-
     *
   ...
-1..65
+1..68
 # 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.
-# tests 65
+# tests 68
 # pass 27
-# fail 21
+# fail 24
 # cancelled 2
 # skipped 10
 # todo 5

test/message/test_runner_output_cli.out

@@ -448,6 +448,10 @@ TAP version 13
       code: 'ERR_TEST_FAILURE'
       stack: |-
         *
+        *
+        *
+        *
+        *
       ...
     # Subtest: callback async throw
     not ok 51 - callback async throw
@@ -621,8 +625,78 @@ TAP version 13
         *
         *
       ...
+    # Subtest: should print error cause
+    not ok 65 - should print error cause
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'foo'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    # Subtest: should print error cause for nested errors
+    not ok 66 - should print error cause for nested errors
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'a'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    # Subtest: should handle cycles in error
+    not ok 67 - should handle cycles in error
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'b'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+       *
+      ...
     # Subtest: invalid subtest fail
-    not ok 65 - invalid subtest fail
+    not ok 68 - invalid subtest fail
       ---
       duration_ms: *
       failureType: 'parentAlreadyFinished'
@@ -631,7 +705,7 @@ TAP version 13
       stack: |-
         *
       ...
-    1..65
+    1..68
     # 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.

test/message/test_runner_output_dot_reporter.out

@@ -1,4 +1,5 @@
 ..XX...X..XXX.X.....
 XXX.....X..X...X....
 .........X...XXX.XX.
-.....XXXXXXX...XXXX
+.....XXXXXXX...XXXXX
+XX

test/message/test_runner_output_spec_reporter.out

@@ -262,6 +262,65 @@
   *
   *
 
+ should print error cause (*ms)
+  Error: foo
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+
+ should print error cause for nested errors (*ms)
+  Error: a
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+
+ should handle cycles in error (*ms)
+  <ref *1> Error: b
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+  *
+
  invalid subtest fail (*ms)
   'test could not be started because its parent finished'
 
@@ -271,9 +330,9 @@
  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.
- tests 65
+ tests 68
  pass 27
- fail 21
+ fail 24
  cancelled 2
  skipped 10
  todo 5