test_runner: bootstrap reporters before running tests #46737

MoLow · 2023-02-19T19:16:17Z

Fixes: #46747

I believe this will address these test failures:
https://ci.nodejs.org/job/node-test-binary-windows-js-suites/19156/

nodejs-github-bot · 2023-02-19T19:16:21Z

Review requested:

@nodejs/test_runner

nodejs-github-bot · 2023-02-19T19:26:16Z

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

MoLow · 2023-02-19T21:49:55Z

@nodejs/test_runner this only solves one issue, there seems to be another issue with the process not being alive long enough to pipe the entire stream, see
https://ci.nodejs.org/job/node-test-commit-plinux/nodes=rhel8-ppc64le/47011/
and #22088 (comment)

not ok 9 - should support a 'js' file as a custom reporter
21:45:52           ---
21:45:52           duration_ms: 1125.36918
21:45:52           failureType: 'testCodeFailure'
21:45:52           error: |-
21:45:52             The input did not match the regular expression /{"test:start":4,"test:pass":2,"test:fail":2,"test:plan":2,"test:diagnostic":\d+}$/. Input:
21:45:52             
21:45:52             'custom.js {"test:start":1}'
21:45:52             
21:45:52           code: 'ERR_ASSERTION'
21:45:52           actual: 'custom.js {"test:start":1}'
21:45:52           operator: 'match'
21:45:52           stack: |-
21:45:52             Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-plinux/nodes/rhel8-ppc64le/test/parallel/test-runner-reporters.js:93:14)
21:45:52             ItTest.runInAsyncScope (node:async_hooks:206:9)
21:45:52             ItTest.run (node:internal/test_runner/test:552:25)
21:45:52             ItTest.start (node:internal/test_runner/test:468:17)
21:45:52             node:internal/test_runner/test:811:71
21:45:52             node:internal/per_context/primordials:470:82
21:45:52             new Promise (<anonymous>)
21:45:52             new SafePromise (node:internal/per_context/primordials:438:29)
21:45:52             node:internal/per_context/primordials:470:9
21:45:52             Array.map (<anonymous>)

I am trying to work on the additional issue on a separate PR

nodejs-github-bot · 2023-02-19T21:51:05Z

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

cjihrig · 2023-02-19T21:52:48Z

Should we wait for the child process's 'close' event instead of 'exit'?

MoLow · 2023-02-19T21:56:53Z

Should we wait for the child process's 'close' event instead of 'exit'?

once the child process is not alive, transforming the output asynchronously is not enough for keeping the main process alive

I have solved that like this:

@@ -123,13 +125,16 @@ function setup(root) {
   const rejectionHandler =
     createProcessEventHandler('unhandledRejection', root);
   const coverage = configureCoverage(root);
-  const exitHandler = () => {
+  const exitHandler = async () => {
     root.coverage = collectCoverage(root, coverage);
     root.postRun(new ERR_TEST_FAILURE(
       'Promise resolution is still pending but the event loop has already resolved',
       kCancelledByParent));
 
     hook.disable();
+    const handle = setInterval(() => {}, 1000);
+    await finished(root.reporter);
+    clearInterval(handle);
     process.removeListener('unhandledRejection', rejectionHandler);
     process.removeListener('uncaughtException', exceptionHandler);
   };

but that is kind of a hack

MoLow · 2023-02-20T08:56:08Z

if anyone wants to tackle this it reproduces running tools/test.py -J test/parallel/test-runner-reporters.js --repeat 1000

cjihrig · 2023-02-20T16:35:52Z

it reproduces running

Interestingly, I haven't been able to get it to reproduce on my machine (M1 mac).

but that is kind of a hack

Definitely a hack, but if there is no way to keep the process alive, I'd be OK with doing something like that, but I think it should exist in run() and the interval period should be large.

MoLow · 2023-02-21T06:11:49Z

Interestingly, I haven't been able to get it to reproduce on my machine (M1 mac).

Mine is a M1 mac as well 😕

MoLow · 2023-02-21T06:30:48Z

I think it should exist in run()

@cjihrig I have tried that but it creates a deadlock - adding a timer prevents the process from reaching beforeExit since the event loop hasn't ended,
but the reporter/s are not ended/drained yet since root.postRun is only called within beforeExit
WDYT?

targos · 2023-02-21T07:31:44Z

lib/internal/test_runner/test.js

+      // In case the event loop has ended and reporter has not drained,
+      // we use a timer to keep the process alive until the reporter is done.
+      const handle = setInterval(() => {}, TIMEOUT_MAX);
+      this.reporter.once('close', () => clearInterval(handle));


How is the stream still working but not keeping the process alive? Is there a resource somewhere that we unref()d ?

see #22088 (comment)
the reporters transform the output after the child process are done

By the way, do we have any idea which change introduced the current flakiness? After the CI was unlocked from the security release, a flurry of changes landed and then this test became flaky. Are we able to bisect it?

I am bisecting now

@cjihrig according to git bisect flakiness started after b4a962d landed, so it would have probably become flaky even without the latest test runner changes.
CC @debadree25 @nodejs/streams

Interesting, investigating then, could you guide me if at any place in the test_runner code where pipeline maybe being used?

I assume the timing condition we might be facing is within setupTestReporters
where getReportersMap is fulfilled after all the tests completed running

node/lib/internal/test_runner/utils.js

Lines 151 to 158 in 5e954c3

async function setupTestReporters(testsStream) {

const { reporters, destinations } = parseCommandLine();

const reportersMap = await getReportersMap(reporters, destinations);

for (let i = 0; i < reportersMap.length; i++) {

const { reporter, destination } = reportersMap[i];

compose(testsStream, reporter).pipe(destination);

}

}

Ah understood, thank you checking this

For the record: I think the issue is in the test runner, not in change performed to streams

So far no success in thinking with reference to b4a962d only think that comes to mind is if anyway testsStream ended before somehow? but that also doesn't hold up much 😕 nonetheless will try explore a little more just incase

cjihrig

LGTM if the CI passes - definitely nicer than adding a keep alive timer.

doc/api/test.md

nodejs-github-bot · 2023-02-21T18:23:33Z

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

nodejs-github-bot · 2023-02-21T19:30:15Z

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

nodejs-github-bot · 2023-02-21T20:56:00Z

Commit Queue failed

- Loading data for nodejs/node/pull/46737
✔  Done loading data for nodejs/node/pull/46737
----------------------------------- PR info ------------------------------------
Title      test_runner: bootstrap reporters before running tests (#46737)
Author     Moshe Atlow  (@MoLow)
Branch     MoLow:wait-for-parser-to-finish -> nodejs:main
Labels     flaky-test, author ready, needs-ci, dont-land-on-v14.x, test_runner
Commits    1
 - test_runner: bootstrap reporters before running tests
Committers 1
 - Moshe Atlow 
PR-URL: https://github.com/nodejs/node/pull/46737
Fixes: https://github.com/nodejs/node/issues/46747
Reviewed-By: Benjamin Gruenbaum 
Reviewed-By: Colin Ihrig 
------------------------------ Generated metadata ------------------------------
PR-URL: https://github.com/nodejs/node/pull/46737
Fixes: https://github.com/nodejs/node/issues/46747
Reviewed-By: Benjamin Gruenbaum 
Reviewed-By: Colin Ihrig 
--------------------------------------------------------------------------------
   ℹ  This PR was created on Sun, 19 Feb 2023 19:16:17 GMT
   ✔  Approvals: 2
   ✔  - Benjamin Gruenbaum (@benjamingr): https://github.com/nodejs/node/pull/46737#pullrequestreview-1308076791
   ✔  - Colin Ihrig (@cjihrig) (TSC): https://github.com/nodejs/node/pull/46737#pullrequestreview-1307932394
   ✖  GitHub CI is still running
   ℹ  Last Full PR CI on 2023-02-21T19:30:15Z: https://ci.nodejs.org/job/node-test-pull-request/49848/
- Querying data for job/node-test-pull-request/49848/
   ✔  Last Jenkins CI successful
--------------------------------------------------------------------------------
   ✔  Aborted `git node land` session in /home/runner/work/node/node/.ncu

https://github.com/nodejs/node/actions/runs/4236769504

PR-URL: #46737 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

MoLow · 2023-02-21T21:13:54Z

Landed in ce49f79

PR-URL: nodejs#46737 Fixes: nodejs#46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

PR-URL: #46737 Backport-PR-URL: #46839 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

PR-URL: #46737 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

MoLow added flaky-test Issues and PRs related to the tests with unstable failures on the CI. fast-track PRs that do not need to wait for 48 hours to land. test_runner labels Feb 19, 2023

This comment was marked as outdated.

Sign in to view

nodejs-github-bot added dont-land-on-v14.x needs-ci PRs that need a full CI run. labels Feb 19, 2023

MoLow added the request-ci Add this label to start a Jenkins CI on a PR. label Feb 19, 2023

github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Feb 19, 2023

benjamingr approved these changes Feb 19, 2023

View reviewed changes

cjihrig approved these changes Feb 19, 2023

View reviewed changes

github-actions bot mentioned this pull request Feb 20, 2023

CI Reliability 2023-02-20 nodejs/reliability#501

Open

24 tasks

joyeecheung mentioned this pull request Feb 20, 2023

parallel/test-runner-reporters is flaking #46747

Closed

github-actions bot mentioned this pull request Feb 21, 2023

CI Reliability 2023-02-21 nodejs/reliability#502

Open

26 tasks

MoLow force-pushed the wait-for-parser-to-finish branch from afc52f4 to 6a24768 Compare February 21, 2023 06:42

MoLow requested review from benjamingr and cjihrig February 21, 2023 06:43

targos reviewed Feb 21, 2023

View reviewed changes

MoLow removed the fast-track PRs that do not need to wait for 48 hours to land. label Feb 21, 2023

MoLow force-pushed the wait-for-parser-to-finish branch from 6a24768 to 6ea5d9c Compare February 21, 2023 18:00

MoLow removed the request for review from benjamingr February 21, 2023 18:00

cjihrig approved these changes Feb 21, 2023

View reviewed changes

doc/api/test.md Outdated Show resolved Hide resolved

test_runner: bootstrap reporters before running tests

d326348

MoLow force-pushed the wait-for-parser-to-finish branch from d92b981 to d326348 Compare February 21, 2023 18:10

MoLow added request-ci Add this label to start a Jenkins CI on a PR. author ready PRs that have at least one approval, no pending requests for changes, and a CI started. labels Feb 21, 2023

github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Feb 21, 2023

benjamingr approved these changes Feb 21, 2023

View reviewed changes

MoLow added the commit-queue Add this label to land a pull request using GitHub Actions. label Feb 21, 2023

nodejs-github-bot added commit-queue-failed An error occurred while landing this pull request using GitHub Actions. and removed commit-queue Add this label to land a pull request using GitHub Actions. labels Feb 21, 2023

MoLow added a commit that referenced this pull request Feb 21, 2023

test_runner: bootstrap reporters before running tests

ce49f79

PR-URL: #46737 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

MoLow merged commit b6f5a67 into nodejs:main Feb 21, 2023

MoLow deleted the wait-for-parser-to-finish branch February 21, 2023 21:14

This was referenced Feb 22, 2023

CI Reliability 2023-02-22 nodejs/reliability#503

Open

CI Reliability 2023-02-23 nodejs/reliability#504

Open

MoLow added a commit to MoLow/node that referenced this pull request Feb 25, 2023

test_runner: bootstrap reporters before running tests

5025bb2

PR-URL: nodejs#46737 Fixes: nodejs#46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

MoLow added a commit to MoLow/node that referenced this pull request Feb 25, 2023

test_runner: bootstrap reporters before running tests

9879adc

PR-URL: nodejs#46737 Fixes: nodejs#46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

MoLow added backport-open-v18.x Indicate that the PR has an open backport. and removed commit-queue-failed An error occurred while landing this pull request using GitHub Actions. labels Feb 25, 2023

MoLow added a commit to MoLow/node that referenced this pull request Feb 25, 2023

test_runner: bootstrap reporters before running tests

69100c9

PR-URL: nodejs#46737 Fixes: nodejs#46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

juanarbol pushed a commit that referenced this pull request Mar 3, 2023

test_runner: bootstrap reporters before running tests

faedcde

PR-URL: #46737 Backport-PR-URL: #46839 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

juanarbol mentioned this pull request Mar 3, 2023

V18.15.0 proposal #46920

Merged

juanarbol pushed a commit that referenced this pull request Mar 5, 2023

test_runner: bootstrap reporters before running tests

28a1317

PR-URL: #46737 Backport-PR-URL: #46839 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

targos pushed a commit that referenced this pull request Mar 13, 2023

test_runner: bootstrap reporters before running tests

3641388

PR-URL: #46737 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

targos pushed a commit that referenced this pull request Mar 14, 2023

test_runner: bootstrap reporters before running tests

6d32a16

PR-URL: #46737 Fixes: #46747 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>

targos mentioned this pull request Mar 14, 2023

v19.8.0 release proposal #47087

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

test_runner: bootstrap reporters before running tests #46737

test_runner: bootstrap reporters before running tests #46737

MoLow commented Feb 19, 2023 •

edited

nodejs-github-bot commented Feb 19, 2023

This comment was marked as outdated.

nodejs-github-bot commented Feb 19, 2023

MoLow commented Feb 19, 2023 •

edited

nodejs-github-bot commented Feb 19, 2023

cjihrig commented Feb 19, 2023

MoLow commented Feb 19, 2023 •

edited

MoLow commented Feb 20, 2023

cjihrig commented Feb 20, 2023

MoLow commented Feb 21, 2023

MoLow commented Feb 21, 2023

targos Feb 21, 2023

MoLow Feb 21, 2023

cjihrig Feb 21, 2023

MoLow Feb 21, 2023

MoLow Feb 21, 2023

debadree25 Feb 21, 2023

MoLow Feb 21, 2023

debadree25 Feb 21, 2023

MoLow Feb 21, 2023 •

edited

debadree25 Feb 21, 2023

cjihrig left a comment

nodejs-github-bot commented Feb 21, 2023

nodejs-github-bot commented Feb 21, 2023

nodejs-github-bot commented Feb 21, 2023

MoLow commented Feb 21, 2023

	async function setupTestReporters(testsStream) {
	const { reporters, destinations } = parseCommandLine();
	const reportersMap = await getReportersMap(reporters, destinations);
	for (let i = 0; i < reportersMap.length; i++) {
	const { reporter, destination } = reportersMap[i];
	compose(testsStream, reporter).pipe(destination);
	}
	}

test_runner: bootstrap reporters before running tests #46737

test_runner: bootstrap reporters before running tests #46737

Conversation

MoLow commented Feb 19, 2023 • edited

nodejs-github-bot commented Feb 19, 2023

This comment was marked as outdated.

nodejs-github-bot commented Feb 19, 2023

MoLow commented Feb 19, 2023 • edited

nodejs-github-bot commented Feb 19, 2023

cjihrig commented Feb 19, 2023

MoLow commented Feb 19, 2023 • edited

MoLow commented Feb 20, 2023

cjihrig commented Feb 20, 2023

MoLow commented Feb 21, 2023

MoLow commented Feb 21, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

MoLow Feb 21, 2023 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cjihrig left a comment

Choose a reason for hiding this comment

nodejs-github-bot commented Feb 21, 2023

nodejs-github-bot commented Feb 21, 2023

nodejs-github-bot commented Feb 21, 2023

MoLow commented Feb 21, 2023

MoLow commented Feb 19, 2023 •

edited

MoLow commented Feb 19, 2023 •

edited

MoLow commented Feb 19, 2023 •

edited

MoLow Feb 21, 2023 •

edited