Skip to content

test_runner: incorrect unwrapping of errors in after() when using the tap reporter #48941

Closed
#48942
Closed
test_runner: incorrect unwrapping of errors in after() when using the tap reporter#48941
#48942
Labels
confirmed-bugIssues and PRs for confirmed bugs.test_runnerIssues and PRs related to the test runner subsystem.

Description

@mcollina
mcollina
opened on Jul 27, 2023

Consider this test:

const test = require('node:test')

test('should print the error', (t) => {
  t.after(async () => {
    throw new Error('kaboom')
  })
})

If I run it normally, I get:

✖ should print the error (0.880917ms)
  Error: kaboom
      at TestContext.<anonymous> (/Users/matteo/tmp/bug.js:5:11)
      at TestHook.runInAsyncScope (node:async_hooks:206:9)
      at TestHook.run (node:internal/test_runner/test:580:25)
      at TestHook.run (node:internal/test_runner/test:759:18)
      at TestHook.run (node:internal/util:500:12)
      at node:internal/test_runner/test:516:20
      at async Test.runHook (node:internal/test_runner/test:514:7)
      at async after (node:internal/test_runner/test:542:9)
      at async Test.run (node:internal/test_runner/test:590:7)
      at async startSubtest (node:internal/test_runner/harness:204:3)

ℹ tests 1
ℹ suites 0
ℹ pass 0
ℹ fail 1
ℹ cancelled 0
ℹ skipped 0
ℹ todo 0
ℹ duration_ms 40.280833

✖ failing tests:

✖ should print the error (0.880917ms)
  Error: kaboom
      at TestContext.<anonymous> (/Users/matteo/tmp/bug.js:5:11)
      at TestHook.runInAsyncScope (node:async_hooks:206:9)
      at TestHook.run (node:internal/test_runner/test:580:25)
      at TestHook.run (node:internal/test_runner/test:759:18)
      at TestHook.run (node:internal/util:500:12)
      at node:internal/test_runner/test:516:20
      at async Test.runHook (node:internal/test_runner/test:514:7)
      at async after (node:internal/test_runner/test:542:9)
      at async Test.run (node:internal/test_runner/test:590:7)
      at async startSubtest (node:internal/test_runner/harness:204:3)

If I run in a non-interactive process such as node --test bug.js | less, I get the error detail scrambled:

TAP version 13
# Subtest: should print the error
not ok 1 - should print the error
  ---
  duration_ms: 0.974875
  failureType: 'hookFailed'
  error: 'failed running after hook'
  code: 'ERR_TEST_FAILURE'
  stack: |-
    TestContext.<anonymous> (/Users/matteo/tmp/bug.js:5:11)
    TestHook.runInAsyncScope (node:async_hooks:206:9)
    TestHook.run (node:internal/test_runner/test:580:25)
    TestHook.run (node:internal/test_runner/test:759:18)
    TestHook.run (node:internal/util:500:12)
    node:internal/test_runner/test:516:20
    async Test.runHook (node:internal/test_runner/test:514:7)
    async after (node:internal/test_runner/test:542:9)
    async Test.run (node:internal/test_runner/test:590:7)
    async startSubtest (node:internal/test_runner/harness:204:3)
  ...
1..1
# tests 1
# suites 0
# pass 0
# fail 1
# cancelled 0
# skipped 0
# todo 0
# duration_ms 43.341875

This shows specifically during CI runs, where the pretty reporter is not engaged.

Activity

  1. mcollina
    added
    confirmed-bugIssues and PRs for confirmed bugs.
    test_runnerIssues and PRs related to the test runner subsystem.
    on Jul 27, 2023
  2. mcollina
    changed the title [-]test: wrong unwrapping of errors in after() when using the --test flag[/-] [+]test_runner: wrong unwrapping of errors in after() when using the --test flag[/+] on Jul 27, 2023
  3. mcollina
    changed the title [-]test_runner: wrong unwrapping of errors in after() when using the --test flag[/-] [+]test_runner: incorrect unwrapping of errors in after() when using the --test flag[/+] on Jul 27, 2023

  4. mcollina commented on Jul 27, 2023

    @mcollina
    mcollina
    on Jul 27, 2023
    SponsorMemberAuthor

    Closing. I was using v18.16.1 and in v18.17.0 is fixed.

  5. mcollina
    closed this as completedon Jul 27, 2023
  6. mcollina
    reopened this on Jul 27, 2023

  7. mcollina commented on Jul 27, 2023

    @mcollina
    mcollina
    on Jul 27, 2023
    SponsorMemberAuthor

    Actually it's a problem, updating the report.

  8. cjihrig commented on Jul 27, 2023

    @cjihrig
    cjihrig
    on Jul 27, 2023
    Contributor

    This appears to be a bug with the TAP reporter.

  9. mcollina
    changed the title [-]test_runner: incorrect unwrapping of errors in after() when using the --test flag[/-] [+]test_runner: incorrect unwrapping of errors in after() when using the tap reporter[/+] on Jul 27, 2023

  10. cjihrig commented on Jul 27, 2023

    @cjihrig
    cjihrig
    on Jul 27, 2023
    Contributor

    This seems to fix it:

    diff --git a/lib/internal/test_runner/reporter/tap.js b/lib/internal/test_runner/reporter/tap.js
index 4aec4ba072..e22c647669 100644
--- a/lib/internal/test_runner/reporter/tap.js
+++ b/lib/internal/test_runner/reporter/tap.js
@@ -198,15 +198,14 @@ function jsToYaml(indent, name, value, seen) {
       errStack = cause?.stack ?? errStack;
       errCode = cause?.code ?? errCode;
       errName = cause?.name ?? errName;
+      errMsg = cause?.message ?? errMsg;
+
       if (isAssertionLike(cause)) {
         errExpected = cause.expected;
         errActual = cause.actual;
         errOperator = cause.operator ?? errOperator;
         errIsAssertion = true;
       }
-      if (failureType === kTestCodeFailure) {
-        errMsg = cause?.message ?? errMsg;
-      }
     }
 
     result += jsToYaml(indent, 'error', errMsg, seen);
  11. cjihrig
    added a commit that references this issue on Jul 27, 2023

    test_runner: unwrap error message in TAP reporter

    5c57d1f

  12. cjihrig commented on Jul 27, 2023

    @cjihrig
    cjihrig
    on Jul 27, 2023
    Contributor

    Proposed fix in #48942

  13. nodejs-github-bot
    closed this as completedin #48942on Jul 29, 2023
  14. nodejs-github-bot
    added a commit that references this issue on Jul 29, 2023

    test_runner: unwrap error message in TAP reporter

    bef3942
  15. Ceres6
    added 2 commits that reference this issue on Aug 14, 2023

    test_runner: unwrap error message in TAP reporter

    eac5bb0

    test_runner: unwrap error message in TAP reporter

    8165b6b
  16. UlisesGascon
    added a commit that references this issue on Aug 14, 2023

    test_runner: unwrap error message in TAP reporter

    b4cfbcd
  17. RafaelGSS
    added 3 commits that reference this issue on Aug 15, 2023

    test_runner: unwrap error message in TAP reporter

    ab31138

    test_runner: unwrap error message in TAP reporter

    9326f0b

    test_runner: unwrap error message in TAP reporter

    5ccfb8d
  18. targos
    added a commit that references this issue on Nov 27, 2023

    test_runner: unwrap error message in TAP reporter

    9f122be
  19. sercher
    added 2 commits that reference this issue on Apr 25, 2024

    test_runner: unwrap error message in TAP reporter

    10c8c4f

    test_runner: unwrap error message in TAP reporter

    8152009
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    confirmed-bugIssues and PRs for confirmed bugs.test_runnerIssues and PRs related to the test runner subsystem.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions