test: correct test-worker-eventlooputil by Flarna · Pull Request #35891 · nodejs/node · GitHub

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request.

If sending back the message is slow for some reason the test fails.

Adapt the test to compare the time seen inside the worker with the time read from main thread.

Fixes: #35844
Refs: #35886
Refs: #35664

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread.

@trevnorris Would be nice if you could take a look. Maybe I misunderstood your test.

Stress test on master, no concurrency: https://ci.nodejs.org/job/node-stress-single-test/191/ ✅

Stress test with this PR, no concurrency: https://ci.nodejs.org/job/node-stress-single-test/192/ ✅

Stress test on master run with -J: https://ci.nodejs.org/job/node-stress-single-test/193/ ❌ (11 failures in 1000 runs)

Stress test with this PR and -J: https://ci.nodejs.org/job/node-stress-single-test/194/ ❌ (1 failure in 1000 runs)

Stress test on master, no concurrency: https://ci.nodejs.org/job/node-stress-single-test/191/ ✅

Stress test with this PR, no concurrency: https://ci.nodejs.org/job/node-stress-single-test/192/ ✅

Stress test on master run with -J: https://ci.nodejs.org/job/node-stress-single-test/193/ ❌ (11 failures in 1000 runs)

Stress test with this PR and -J: https://ci.nodejs.org/job/node-stress-single-test/194/ ❌ (1 failure in 1000 runs)

Based on these results, this change greatly improves things but won't completely solve the problem. (I'll take "greatly improves" for sure!) However moving the test to sequential (along with these changes or without) will resolve the issue. (The question is whether that should resolve the issue or if the fact that it does is also indicative of a bug.)

@Trott Thanks for running the perf tests.

The fail remaining is at a different location. I will look into this further once I'm back on my work place.

I am also thinking whether the spin time 50 ms is too small in comparison with the message overhead (looking at the failure data in freebsd, these come to 200 - 300 ms range), and as the later could potentially depend on the system characteristics (such as cpu count, load on the system etc.) , I doubt if the value idleActive(w2) is reflective of anything at all!

Fixed the issue seen in last stress test by exchanging the two calls to get elu to be compared. Seems if OS decides to schedule an other process between these two lines the test failed.

new (2000) run: https://ci.nodejs.org/job/node-stress-single-test/195/ ✅

Considering that this test heavily depends on timing it's maybe better to move it into sequential to avoid/reduce side effects of high os load/low number of CPUs.

Hi all. Finally got done with my NodeConf Remote talk. Will prioritize looking at this and helping get it fixed (nothing worse than flakey tests failing CI). Give me a bit to review everything.

Make this additional change:

--- a/test/parallel/test-worker-eventlooputil.js
+++ b/test/parallel/test-worker-eventlooputil.js
@@ -50,12 +50,13 @@ let workerELU;
   if (eventLoopUtilization().idle <= 0)
     return setTimeout(mustCall(r), 5);
 
+  mainElu = eventLoopUtilization();
+
   worker = new Worker(__filename, { argv: [ 'iamalive' ] });
   metricsCh = new MessageChannel();
   worker.postMessage({ metricsCh: metricsCh.port1 }, [ metricsCh.port1 ]);
 
   workerELU = worker.performance.eventLoopUtilization;
-  mainElu = eventLoopUtilization();
   metricsCh.port2.once('message', mustCall(checkWorkerIdle));
   metricsCh.port2.postMessage({ cmd: 'elu' });
   // Make sure it's still safe to call eventLoopUtilization() after the worker

The ELU of the main thread should be stored the moment it's ready for testing.

Completely remove the eluDiff test. I don't remember what I was thinking when I added this, but the syntax is invalid. The diff between different ELU's is only valid for the same thread. This does a diff between worker and parent.

done.

We could add worker.threadId into the elu result and throw on mismatch as it is a clear wrong use.

LGTM with change suggested by @trevnorris

CI: https://ci.nodejs.org/job/node-test-pull-request/34032/
stress test: https://ci.nodejs.org/job/node-stress-single-test/196/

Landed in 58280ff...9dbde1d

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: #35891 Fixes: #35844 Refs: #35886 Refs: #35664 Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Rich Trott <rtrott@gmail.com>

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Backport-PR-URL: nodejs#37163

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: #35891 Fixes: #35844 Refs: #35886 Refs: #35664 Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Backport-PR-URL: #37163

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Backport-PR-URL: nodejs#37165

The active worker check compared the time from sending message till response arrived from worker with the complete time the worker was running till it responses to the spin request. If sending back the message is slow for some reason the test fails. Adapt the test to compare the time seen inside the worker with the time read from main thread. PR-URL: #35891 Fixes: #35844 Refs: #35886 Refs: #35664 Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Backport-PR-URL: #37163

nodejs-github-bot added the test Issues and PRs related to the tests. label Oct 31, 2020

Trott mentioned this pull request Oct 31, 2020

test: mark test-worker-eventlooputil flaky #35886

Closed

watilde added the request-ci Add this label to start a Jenkins CI on a PR. label Oct 31, 2020

github-actions Bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Oct 31, 2020

This comment has been minimized.

Sign in to view

gireeshpunathil reviewed Oct 31, 2020

View reviewed changes

Comment thread test/parallel/test-worker-eventlooputil.js

Comment thread test/parallel/test-worker-eventlooputil.js

gireeshpunathil approved these changes Nov 1, 2020

View reviewed changes

This comment has been minimized.

Sign in to view

Flarna added the wip Issues and PRs that are still a work in progress. label Nov 1, 2020

fixup! test: correct test-worker-eventlooputil

4374323

trevnorris approved these changes Nov 2, 2020

View reviewed changes

Trott approved these changes Nov 3, 2020

View reviewed changes

fixup! test: correct test-worker-eventlooputil

932350e

Flarna added perf_hooks Issues and PRs related to the implementation of the Performance Timing API. worker Issues and PRs related to Worker support. request-ci Add this label to start a Jenkins CI on a PR. and removed wip Issues and PRs that are still a work in progress. labels Nov 3, 2020

github-actions Bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Nov 3, 2020

This comment has been minimized.

Sign in to view

Flarna added author ready PRs that have at least one approval, no outstanding review comments, and a CI started. commit-queue Add this label to land a pull request using GitHub Actions. labels Nov 3, 2020

github-actions Bot removed the commit-queue Add this label to land a pull request using GitHub Actions. label Nov 4, 2020

github-actions Bot closed this Nov 4, 2020

Flarna deleted the fix-test-worker-eventlooputil branch November 4, 2020 07:20

targos mentioned this pull request Nov 4, 2020

v15.1.0 release proposal #35948

Merged

BethGriggs added the backport-blocked-v14.x label Dec 7, 2020

This was referenced Feb 1, 2021

[v14.x backport] worker: add eventLoopUtilization() #37163

Closed

[v12.x backport] worker: add eventLoopUtilization() #37165

Merged

richardlau mentioned this pull request Mar 18, 2021

v12.22.0 proposal #37797

Merged

danielleadams mentioned this pull request May 3, 2021

v14.17.0 proposal #38507

Merged

targos removed the backport-blocked-v14.x label May 30, 2021

-                const tmpMainElu = eventLoopUtilization(mainElu);
                 const perfWorkerElu = workerELU();
+                const tmpMainElu = eventLoopUtilization(mainElu);
                 const eluDiff = eventLoopUtilization(perfWorkerElu, mainElu);

test: correct test-worker-eventlooputil by Flarna · Pull Request #35891 · nodejs/node · GitHub

Uh oh!

Uh oh!

test: correct test-worker-eventlooputil - #35891

test: correct test-worker-eventlooputil#35891Flarna wants to merge 3 commits intonodejs:masternodejs/node:masterfrom dynatrace-oss-contrib:fix-test-worker-eventlooputildynatrace-oss-contrib/node:fix-test-worker-eventlooputilCopy head branch name to clipboard

Conversation

Flarna commented Oct 31, 2020

Uh oh!

Flarna commented Oct 31, 2020

Uh oh!

Trott commented Oct 31, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

This comment has been minimized.

Uh oh!

Uh oh!

Trott commented Oct 31, 2020

Uh oh!

Flarna commented Nov 1, 2020

Uh oh!

gireeshpunathil commented Nov 1, 2020

Uh oh!

This comment has been minimized.

Flarna commented Nov 2, 2020

Uh oh!

trevnorris commented Nov 2, 2020

Uh oh!

trevnorris left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

trevnorris Nov 2, 2020

Choose a reason for hiding this comment

Uh oh!

Flarna Nov 3, 2020

Choose a reason for hiding this comment

Uh oh!

Trott left a comment

Choose a reason for hiding this comment

Uh oh!

This comment has been minimized.

nodejs-github-bot commented Nov 3, 2020 • edited by Flarna Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

github-actions Bot commented Nov 4, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

8 participants

test: correct test-worker-eventlooputil#35891
Flarna wants to merge 3 commits into
nodejs:masterfrom
dynatrace-oss-contrib:fix-test-worker-eventlooputil

Trott commented Oct 31, 2020 •
edited
Loading

trevnorris left a comment •
edited
Loading

nodejs-github-bot commented Nov 3, 2020 •
edited by Flarna
Loading