test: correct test-worker-eventlooputil #35891

Flarna · 2020-10-31T00:22:25Z

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.

Flarna · 2020-10-31T00:22:59Z

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

Trott · 2020-10-31T04:13:16Z

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)

test/parallel/test-worker-eventlooputil.js

Trott · 2020-10-31T11:54:13Z

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.)

Flarna · 2020-11-01T11:54:22Z

@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.

gireeshpunathil · 2020-11-01T12:18:48Z

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!

Flarna · 2020-11-02T08:57:22Z

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.

trevnorris · 2020-11-02T22:39:29Z

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.

trevnorris

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.

test/parallel/test-worker-eventlooputil.js

trevnorris · 2020-11-02T23:13:45Z

test/parallel/test-worker-eventlooputil.js

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


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.

Trott

LGTM with change suggested by @trevnorris

nodejs-github-bot · 2020-11-03T09:14:00Z

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

github-actions · 2020-11-04T07:19:51Z

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 <[email protected]> Reviewed-By: Rich Trott <[email protected]>

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 <[email protected]> Reviewed-By: Rich Trott <[email protected]> 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: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> 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: nodejs#35891 Fixes: nodejs#35844 Refs: nodejs#35886 Refs: nodejs#35664 Reviewed-By: Gireesh Punathil <[email protected]> Reviewed-By: Rich Trott <[email protected]> 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 <[email protected]> Reviewed-By: Rich Trott <[email protected]> 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 <[email protected]> Reviewed-By: Rich Trott <[email protected]> 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 <[email protected]> Reviewed-By: Rich Trott <[email protected]> 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

test/parallel/test-worker-eventlooputil.js Show resolved Hide resolved

test/parallel/test-worker-eventlooputil.js Show resolved Hide resolved

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 pending requests for changes, 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

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

test: correct test-worker-eventlooputil #35891

test: correct test-worker-eventlooputil #35891

Flarna commented Oct 31, 2020

Flarna commented Oct 31, 2020

Trott commented Oct 31, 2020 •

edited

Loading

This comment has been minimized.

Trott commented Oct 31, 2020

Flarna commented Nov 1, 2020

gireeshpunathil commented Nov 1, 2020

This comment has been minimized.

Flarna commented Nov 2, 2020

trevnorris commented Nov 2, 2020

trevnorris left a comment •

edited

Loading

trevnorris Nov 2, 2020

Flarna Nov 3, 2020

Trott left a comment

This comment has been minimized.

nodejs-github-bot commented Nov 3, 2020 •

edited by Flarna

Loading

github-actions bot commented Nov 4, 2020

test: correct test-worker-eventlooputil #35891

test: correct test-worker-eventlooputil #35891

Conversation

Flarna commented Oct 31, 2020

Flarna commented Oct 31, 2020

Trott commented Oct 31, 2020 • edited Loading

This comment has been minimized.

Trott commented Oct 31, 2020

Flarna commented Nov 1, 2020

gireeshpunathil commented Nov 1, 2020

This comment has been minimized.

Flarna commented Nov 2, 2020

trevnorris commented Nov 2, 2020

trevnorris left a comment • edited Loading

Choose a reason for hiding this comment

trevnorris Nov 2, 2020

Choose a reason for hiding this comment

Flarna Nov 3, 2020

Choose a reason for hiding this comment

Trott left a comment

Choose a reason for hiding this comment

This comment has been minimized.

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

github-actions bot commented Nov 4, 2020

Trott commented Oct 31, 2020 •

edited

Loading

trevnorris left a comment •

edited

Loading

nodejs-github-bot commented Nov 3, 2020 •

edited by Flarna

Loading