Indicate when a test is started in test_runner

[connor4312]

What is the problem this feature will solve?

When running tests in an editor (like VS Code), users want to know what test is currently being executed. This is useful, so if a test is hanging for instance, it's easy to see what it is.

What is the feature you are proposing to solve the problem?

Currently, TAP output for a test like...

describe("math", () => {
  it("addition",async () => {
    strictEqual(1 + 1, 2);
  });
});

looks like this:

# Subtest: math
    # Subtest: addition
    ok 1 - addition
      ---
      duration_ms: 1.369826
      ...

The "Subtest:` comment, and following assertion result, is only printed once the test completes. Two good alternatives would be to:

• Print the Subtest: comment when the test is started, rather than when it finishes, or
• Just print some other comment when the test is started

(The former is breaking for the way I handle logs in VS Code's runner, but this is due to my own hackery; not sure if any others will be affected)

What alternatives have you considered?

No response

[cjihrig]

Printing something probably won't work in all cases - specifically when running tests in parallel.

[MoLow]

we can emit an event on TestsStream for reporters other than TAP to handle it.
if we want to support additional events that TAP doesn't contain we will have to move from tap parsing to some sort of ipc reporter

[connor4312]

That would work fine for my use case; once #46045 is in I would like to switch to .run()

[MoLow]

@connor4312 is this still needed by you?
@RafaelGSS is this a good candidate for Grace Hopper Open Source Day?

[connor4312]

This would still be quite helpful to me and, I believe, most editor integrators.

[sankalp1999]

Hi. I would like to help on this.

[sankalp1999]

I have been looking into the files in lib/internal/test_runner. I went through tests_stream.js, seems relevant for this issue. Am I going in the right direction?

Also to clarify, it's required to use a emit start event for reporters other than TAP i.e for dot and spec. I am finding this part confusing.

we can emit an event on TestsStream for reporters other than TAP to handle it. if we want to support additional events that TAP doesn't contain we will have to move from tap parsing to some sort of ipc reporter

[MoLow]

I have been looking into the files in lib/internal/test_runner. I went through tests_stream.js, seems relevant for this issue. Am I going in the right direction?

yes

Also to clarify, it's required to use a emit start event for reporters other than TAP i.e for dot and spec. I am finding this part confusing.

why is it required? these reports print to stdout when the test has been completed, not when it starts

[sankalp1999]

Hello @MoLow. Thanks for the previous reply.

why is it required? these reports print to stdout when the test has been completed, not when it starts

It's not required. My understanding was wrong back then.

I have made a single line change and attached the draft PR.

Here's the output that I am getting currently. Have added a "starting..." string. Would like to know if
this output aligns with the requirement.

TAP version 13
# Subtest: /Users/sshubham/Desktop/open_source/node/custom_test_dir/test1.mjs starting... 
    # Subtest: addition starting...
# Subtest: math
    # Subtest: addition
    ok 1 - addition
      ---
      duration_ms: 0.309375
      ...
    # Subtest: subtraction starting...
    # Subtest: subtraction
    not ok 2 - subtraction
      ---
      duration_ms: 0.860166
      failureType: 'testCodeFailure'
      error: |-
        Expected values to be strictly deep-equal:
        
        5 !== 2
        
      code: 'ERR_ASSERTION'
      name: 'AssertionError'
      expected: 2
      actual: 5
      operator: 'deepStrictEqual'
      stack: |-
        TestContext.<anonymous> (file:///Users/sshubham/Desktop/open_source/node/custom_test_dir/test1.mjs:9:7)
        Test.runInAsyncScope (node:async_hooks:206:9)
        Test.run (node:internal/test_runner/test:571:25)
        Suite.processPendingSubtests (node:internal/test_runner/test:315:27)
        Test.postRun (node:internal/test_runner/test:640:19)
        Test.run (node:internal/test_runner/test:599:10)
        async Promise.all (index 0)
        async Suite.run (node:internal/test_runner/test:804:7)
        async startSubtest (node:internal/test_runner/harness:203:3)
      ...
    1..2
not ok 1 - math
  ---
  duration_ms: 2.00525
  type: 'suite'
  failureType: 'subtestsFailed'
  error: '1 subtest failed'
  code: 'ERR_TEST_FAILURE'
  ...
    # Subtest: photosynthesis starting...
# Subtest: science
    # Subtest: photosynthesis
    ok 1 - photosynthesis
      ---
      duration_ms: 0.055125
      ...
    1..1
ok 2 - science
  ---
  duration_ms: 0.106167
  type: 'suite'
  ...
1..2
# tests 3
# suites 2
# pass 2
# fail 1
# cancelled 0
# skipped 0
# todo 0
# duration_ms 45.467584

[sankalp1999]

Could you please guide me on tests.

From looking into prev commits, current understanding is: need to add my test output to test/fixtures/test-runner/output
then I perhaps need to write a js file which runs a test and matches the output with above.

Request your guidance here. Thanks.

[connor4312]

Small nit on the event name, I would name it Subtest starting: <name> rather than Subtest: <name> starting... to make it easier to distinguish between starting a subtest and getting a completion for a subtest called e.g.Test something is starting...

(though I don't have the context to know if a comment is the right approach in general here 🙂 )

[MoLow]

Here's the output that I am getting currently. Have added a "starting..." string. Would like to know if
this output aligns with the requirement.

@sankalp1999 there is no intention to change to output of the TAP reporter. the requirement here (if I understand it correctly) is to add a subtest started event to the tests stream,
see the implementation: https://github.com/nodejs/node/blob/d225d957586198ca6e7c63150ef8354bfb7141b9/lib/internal/test_runner/tests_stream.js
and the docs: https://nodejs.org/api/test.html#class-testsstream

this means the event will only be usable through the run API but not via one of the existing reporters

[cjihrig]

Maybe I missed something, but why does the 'test:start' event not handle this use case?

[MoLow]

Maybe I missed something, but why does the 'test:start' event not handle this use case?

test:start is reported in order, and according to the description of this issue, the request is for an event fired immediately when the tests started and not when it is ready to be reported. @connor4312 correct me if I am wrong?

also, firing such an event without affecting the TAP output will not work with the current implementation and might require first moving to use another serialization method, as we discussed on other issues

[cjihrig]

OK that makes sense. Having two separate events makes sense, but the fact that start already means something other than "the test is starting" is a confusing API.

[MoLow]

but the fact that start already means something other than "the test is starting" is a confusing API.

I agree

[benjamingr]

but the fact that start already means something other than "the test is starting" is a confusing API.
I agree

Let's rename it then? It's not too late and now is the time

[cjihrig]

I believe changing the reporter API is considered breaking at this point (but changing the textual output of a reporter is not).

EDIT: Not saying we shouldn't do it though.

[sankalp1999]

Thanks @MoLow. I have made a test:begin (name_to_be_decided) event in the test_streams file since test:start is already being used.

Not sure if I need to make changes in the textual output in the reporters as you mentioned "this means the event will only be usable through the run API but not via one of the existing reporters"

[sankalp1999]

I was going through the docs to see how I can write the setup option (edit:i meant arguments) in the run api in order to emit events. Can someone give me an example. I tried to import the TestsStream object so that I can make a setup function with calls to emit events (if that's how it is done). But for that, I would be using internals which I am not sure a user would be doing. So I guess it's wrong.

Can you give one example on how I can setup custom events using run api.

Now I don't know how that's supposed to be. It's not clear in the docs. Perhaps some examples can be added in the docs for this => On how to use the various options provided with the run api.

const { tap } = require('node:test/reporters');
const process = require('node:process');
const { run } = require('node:test');
const path = require('node:path');
const { TestsStream } = require('../lib/internal/test_runner/tests_stream.js');

run({ files: [path.resolve('./tests/test1.js')]})
.compose(tap)
.pipe(process.stdout);

[sankalp1999]

I think we should add one import/require statement atleast for run api in the docs.

const { run } = require('node:test');

[sankalp1999]

Another candidate for doc change. It says "Emitted when a test starts." which is inconsistent based on what we discussed above.

[sankalp1999]

hi @MoLow . can you have look at the above comments.

[MoLow]

@sankalp1999 the doc changes make sense indeed