node:test - when running node --test the output is not a tap-spec valid output

[ErickWendel]

Version

v18.1.0

Platform

Darwinx86_64

Subsystem

No response

What steps will reproduce the bug?

// index.test.js

import test from 'node:test';
import assert from 'node:assert'

test('top level test', async (t) => {
  await t.test('subtest with error!', (t) => {
    assert.strictEqual(1, 2);
  });

  await t.test('subtest with success!', (t) => {
    assert.strictEqual(1, 1);
  });
});

node --test index.test.js | npx tap-spec
// nothing on the output

node  index.test.js | npx tap-spec
// outputs as expected

/*
  ✖ top level test
    -----------------
    duration_ms: 0.00786128
    failureType: 'subtestsFailed'
    error: '1 subtest failed'
    code: 'ERR_TEST_FAILURE'


  duration_ms 0.120751951
*/

How often does it reproduce? Is there a required condition?

only happens when using the flag --test

What is the expected behavior?

# working
(node:44623) ExperimentalWarning: The test runner is an experimental feature. This feature could change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
TAP version 13
    not ok 1 - subtest with error!
      ---
      duration_ms: 0.1 #omitted to make it easier to diff 
      failureType: 'testCodeFailure'
      error: |-
        Expected values to be strictly equal:
        
        1 !== 2
        
      code: 'ERR_ASSERTION'
      stack: |-
        TestContext.<anonymous> (file:///Users/webapi/index.test.js:6:12)
        Test.runInAsyncScope (node:async_hooks:202:9)
        Test.run (node:internal/test_runner/test:340:20)
        Test.start (node:internal/test_runner/test:292:17)
        TestContext.test (node:internal/test_runner/test:63:20)
        TestContext.<anonymous> (file:///Users/webapi/index.test.js:5:11)
        Test.runInAsyncScope (node:async_hooks:202:9)
        Test.run (node:internal/test_runner/test:340:20)
        Test.start (node:internal/test_runner/test:292:17)
        Test.test (node:internal/test_runner/harness:126:18)
      ...
    ok 2 - subtest with success!
      ---
      duration_ms: 0.1 #omitted to make it easier to diff 
      ...
    1..2
not ok 1 - top level test
  ---
  duration_ms: 0.1 #omitted to make it easier to diff 
  failureType: 'subtestsFailed'
  error: '1 subtest failed'
  code: 'ERR_TEST_FAILURE'
  ...
1..1
# tests 1
# pass 0
# fail 1
# skipped 0
# todo 0
# duration_ms: 0.1 #omitted to make it easier to diff 

What do you see instead?

# not working
TAP version 13
not ok 1 - /Users/webapi/index.test
  ---
  duration_ms: 0.1 #omitted to make it easier to diff 
  failureType: 'subtestsFailed'
  exitCode: 1
  stdout: |-
    TAP version 13
        not ok 1 - subtest with error!
          ---
          duration_ms: 0.1 #omitted to make it easier to diff 
          failureType: 'testCodeFailure'
          error: |-
            Expected values to be strictly equal:
            
            1 !== 2
            
          code: 'ERR_ASSERTION'
          stack: |-
            TestContext.<anonymous> (file:///Users/webapi/index.test:6:12)
            Test.runInAsyncScope (node:async_hooks:202:9)
            Test.run (node:internal/test_runner/test:340:20)
            Test.start (node:internal/test_runner/test:292:17)
            TestContext.test (node:internal/test_runner/test:63:20)
            TestContext.<anonymous> (file:///Users/webapi/index.test:5:11)
            Test.runInAsyncScope (node:async_hooks:202:9)
            Test.run (node:internal/test_runner/test:340:20)
            Test.start (node:internal/test_runner/test:292:17)
            Test.test (node:internal/test_runner/harness:126:18)
          ...
        ok 2 - subtest with success!
          ---
          duration_ms: 0.1 #omitted to make it easier to diff 
          ...
        1..2
    not ok 1 - top level test
      ---
      duration_ms: 0.1 #omitted to make it easier to diff 
      failureType: 'subtestsFailed'
      error: '1 subtest failed'
      code: 'ERR_TEST_FAILURE'
      ...
    1..1
    # tests 1
    # pass 0
    # fail 1
    # skipped 0
    # todo 0
    # duration_ms 0.1 #omitted to make it easier to diff 
    
  stderr: |-
    (node:44602) ExperimentalWarning: The test runner is an experimental feature. This feature could change at any time
    (Use `node --trace-warnings ...` to show where the warning was created)
    
  error: 'test failed'
  code: 'ERR_TEST_FAILURE'
  ...
1..1
# tests 1
# pass 0
# fail 1
# skipped 0
# todo 0
# duration_ms 0.1 #omitted to make it easier to diff 

Additional information

I'm willing to dive into this bug and fix it. I've spoken with @cjihrig and it seems like a confirmed bug

[Trott]

@nodejs/test_runner

[cjihrig]

The problem is the child process stdout and stderr yaml blocks. I commented out these two lines, and tap-spec worked fine.

It can be reproduced without the CLI test runner as well as long as a yaml block contains a blank line:

'use strict';
const test = require('node:test');
const assert = require('node:assert');

test(() => assert.strictEqual(1, 2));

This outputs the following, which tap-spec does not accept:

...
  error: |-
    Expected values to be strictly equal:
    
    1 !== 2
    
  code: 'ERR_ASSERTION'
...

[ErickWendel]

uuh nice! I'm gonna take a look at it and open a PR 🤩

[rubiagatra]

I'll also try to look at it

[rubiagatra]

should we delete that two lines @cjihrig?

Could you guide me in addressing this?

[cjihrig]

I'm not convinced that this is a bug on our end. I think it may be a tap-spec bug.

[MoLow]

Regardless of where the bug originates, I think the solution should be the same as in this issue, parse child process tap output, then join it in to a unified tap output, instead of setting a YAML block with the child process output.

@manekinekko has started implementing this, and I have suggested an alternative approach in the other issue.

[cjihrig]

The TAP parser is in place now (not released yet though) and this seems to work better. I'm going to close this out. Thanks for reporting!