Repository navigation
Indicate when a test is started in test_runner #46727
Description
Activity
Printing something probably won't work in all cases - specifically when running tests in parallel.
we can emit an event on
TestsStreamfor 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 reporterReacted by Benjamin GruenbaumThat would work fine for my use case; once #46045 is in I would like to switch to
.run()@connor4312 is this still needed by you?
@RafaelGSS is this a good candidate for Grace Hopper Open Source Day?This would still be quite helpful to me and, I believe, most editor integrators.
Reacted by Moshe Atlow and Erick WendelHi. I would like to help on this.
Reacted by Moshe Atlow and Debadree ChatterjeeI 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
TestsStreamfor 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 reporterI 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
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.4675844 remaining items
Maybe I missed something, but why does the 'test:start' event not handle this use case?
test:startis 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
OK that makes sense. Having two separate events makes sense, but the fact that
startalready means something other than "the test is starting" is a confusing API.Reacted by Sankalpbut the fact that start already means something other than "the test is starting" is a confusing API.
I agree
Reacted by Benjamin Gruenbaum and Sankalpbut the fact that start already means something other than "the test is starting" is a confusing API.
I agreeLet's rename it then? It's not too late and now is the time
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.
Reacted by Moshe AtlowThanks @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"
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);I think we should add one import/require statement atleast for run api in the docs.
const { run } = require('node:test');
Another candidate for doc change. It says "Emitted when a test starts." which is inconsistent based on what we discussed above.
hi @MoLow . can you have look at the above comments.
@sankalp1999 the doc changes make sense indeed
Reacted by Sankalp- added a commit that references this issue
on May 25, 2023
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...
looks like this:
The "Subtest:` comment, and following assertion result, is only printed once the test completes. Two good alternatives would be to:
Subtest:comment when the test is started, rather than when it finishes, or(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