test_runner: fix global after not failing the tests

[rluvaton]

Fix: #48867

I'm not sure about the solution, WDYT? 🤔

[nodejs-github-bot]

Review requested:

• @nodejs/test_runner

[MoLow]

I wonder if we should change this name. @cjihrig WDYT?

[cjihrig]

I don't think the root test should even show up in the output like this because users will have no clue what it is (the root test is basically an implementation detail). For failed global hooks, I think we should try to do something similar to what we do when we run a test file with no tests that exits with non-zero.

In case it's not clear what I mean:

// foo.js
process.exit(1);

$ node --test foo.js
✖ /private/tmp/foo.js (23.390208ms)
  'test failed'

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

✖ failing tests:

✖ /private/tmp/foo.js (23.390208ms)
  'test failed'

[rluvaton]

updated, can you take a look?

[cjihrig]

Sorry, I should have been a bit more explicit. When I said "something similar" I meant specify the name of the hook, not the filename. For example, "global after hook" or something alone those lines.

[rluvaton]

When the before failed we have:

'use strict';
const { it, before } = require('node:test');

before(() => {
  throw new Error('this should fail the test')
});

it('this is a test', () => {
  console.log('this is a test')
});

✖ this is a test (0.679959ms)
  Error: this should fail the test
      at TestContext.<anonymous> (/Users/rluvaton/dev/open-source/node/node-fork/test/fixtures/test-runner/output/global_after_should_fail_the_test.js:5:9)
      at TestHook.runInAsyncScope (node:async_hooks:206:9)
      at TestHook.run (node:internal/test_runner/test:581:25)
      at TestHook.run (node:internal/test_runner/test:774:18)
      at TestHook.run (node:internal/util:500:12)
      at node:internal/test_runner/test:517:20
      at async Test.runHook (node:internal/test_runner/test:515:7)
      at async Test.run (node:internal/test_runner/test:554:9)
      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 116.542583

✖ failing tests:

✖ this is a test (0.679959ms)
  Error: this should fail the test
      at TestContext.<anonymous> (/Users/rluvaton/dev/open-source/node/node-fork/test/fixtures/test-runner/output/global_after_should_fail_the_test.js:5:9)
      at TestHook.runInAsyncScope (node:async_hooks:206:9)
      at TestHook.run (node:internal/test_runner/test:581:25)
      at TestHook.run (node:internal/test_runner/test:774:18)
      at TestHook.run (node:internal/util:500:12)
      at node:internal/test_runner/test:517:20
      at async Test.runHook (node:internal/test_runner/test:515:7)
      at async Test.run (node:internal/test_runner/test:554:9)
      at async startSubtest (node:internal/test_runner/harness:204:3)

[cjihrig]

With Node 20.5.0, a failing global before() fails the test run with the same error shown in #48913 (comment). I pulled down this PR locally, and verified there is no difference.

With Node 20.5.0, a failing global after() does not fail the test run, and is a bug. This PR does address that, but the failure should be more accurate IMO:

this is a test
✔ this is a test (1.356584ms)
✖ /tmp/foo.js (0.22ms)
  Error: this should fail the test
      at TestContext.<anonymous> (/private/tmp/foo.js:5:9)
      at TestHook.runInAsyncScope (node:async_hooks:206:9)
      at TestHook.run (node:internal/test_runner/test:581:25)
      at TestHook.run (node:internal/test_runner/test:774:18)
      at TestHook.run (node:internal/util:500:12)
      at node:internal/test_runner/test:517:20
      at async Test.runHook (node:internal/test_runner/test:515:7)
      at async after (node:internal/test_runner/test:543:9)
      at async Test.run (node:internal/test_runner/test:591:7)
      at async process.exitHandler (node:internal/test_runner/harness:144:5)

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

✖ failing tests:

✖ /tmp/foo.js (0.22ms)
  Error: this should fail the test
      at TestContext.<anonymous> (/private/tmp/foo.js:5:9)
      at TestHook.runInAsyncScope (node:async_hooks:206:9)
      at TestHook.run (node:internal/test_runner/test:581:25)
      at TestHook.run (node:internal/test_runner/test:774:18)
      at TestHook.run (node:internal/util:500:12)
      at node:internal/test_runner/test:517:20
      at async Test.runHook (node:internal/test_runner/test:515:7)
      at async after (node:internal/test_runner/test:543:9)
      at async Test.run (node:internal/test_runner/test:591:7)
      at async process.exitHandler (node:internal/test_runner/harness:144:5)

Just looking at that output, I would have no idea that the failure is because the after hook failed. That is important information for users. That's what I'm saying we need to change in #48913 (comment).

EDIT: More specifically, it would be good if ✖ /tmp/foo.js (0.22ms) in this example said ✖ global after hook (0.22ms)

[MoLow]

More specifically, it would be good if ✖ /tmp/foo.js (0.22ms) in this example said ✖ global after hook (0.22ms)

it has a failureType: 'hookFailed' , wich is printed in case of the tap reporter, but in spec we seem to omit it.
still - there is a stack trace, isnt that good enough?

[cjihrig]

I mean it's better than the existing bug, but seems like something we could improve 🤷

[rluvaton]

ideally, I would prefer each hook that failed to tell that it failed from that hook

[rluvaton]

I think it should be in a different PR, and in that PR I would also align the before to match the right behavior...

[MoLow]

LGTM

[rluvaton]

The test test/parallel/test-runner-cli.js is failing as it picked up new test files, #48787 would have fixed that

[nodejs-github-bot]

CI: https://ci.nodejs.org/job/node-test-pull-request/52946/

[MoLow]

@rluvaton the new tests seem to fail on windows https://ci.nodejs.org/job/node-test-binary-windows-js-suites/22188/RUN_SUBSET=1,nodes=win2012r2-COMPILED_BY-vs2019-x86/console

00:29:13         not ok 7 - test-runner/output/global_after_should_fail_the_test.js
00:29:13           ---
00:29:13           duration_ms: 780.562048
00:29:13           failureType: 'testCodeFailure'
00:29:13           error: |-
00:29:13             Expected values to be strictly equal:
00:29:13             + actual - expected ... Lines skipped
00:29:13             
00:29:13               'this is a test\n' +
00:29:13                 'TAP version 13\n' +
00:29:13             ...
00:29:13                 '  duration_ms: *\n' +
00:29:13                 '  ...\n' +
00:29:13             +   'not ok 2 - C:\\\\workspace\\\\node-test-binary-windows-js-suites\\\\node\\\\test\\\\fixtures\\\\test-runner\\\\output\\\\global_after_should_fail_the_test.js\n' +
00:29:13             -   'not ok 2 - /test/fixtures/test-runner/output/global_after_should_fail_the_test.js\n' +
00:29:13                 '  ---\n' +
00:29:13             ...
00:29:13                 '# skipped 0\n' +
00:29:13                 '# todo 0\n' +
00:29:13                 '# duration_ms *\n'

[rluvaton]

I pushed a fix, hope this would work

[MoLow]

@rluvaton commits like this dont actually trigger the CI

[rluvaton]

What would you do to trigger a CI?

[nodejs-github-bot]

Landed in c58e8fc

[RafaelGSS]

Due to fact, #48877 didn't land cleanly on v20.x-staging. This PR somehow, depends on it. So we'll need a manual backport.

Reference: https://github.com/nodejs/node/blob/main/doc/contributing/backporting-to-release-lines.md

[rluvaton]

Backport PR:

• [v20.x backport] backport multiple test runner related prs #49225