GV

GeezerVison

The World Wide Web, restored to 800 pixels of glory.

Home|About|Gaming cabinet|Archives|How it works|Starter sites

On this site

  • Sign in
  • ActionsCI/CD and automation
  • CodespacesCloud development environments
  • All Features
  • Documentation
  • Training
  • Certifications
  • Build with Copilot
  • Customize Copilot
  • Integrations
  • Trending repos
  • GitHub Sponsors
  • Developer articles
  • Enterprises

This view

  • Original page
  • New address

GeezerVison is showing github.com — test: fix races in test-performance-eventlooputil by Flarna · Pull Request #36028 · nodejs/node

Conversation

@Flarna

@Flarna Flarna commented Nov 8, 2020 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member

Fix two races in test-performance-eventlooputil resulting in a flaky test.

elu1 was capture after start time t from spin look. If OS descides to reschedule the process after capturing t but before getting elu for >=50ms the spin loop is actually a nop. elu1 doesn't show this and as a result elut3 = eventLoopUtilization(elu1) results in
elu3.active is lower then the expected spin time.
Moving capturing of t after capturing t, just before the spin look
avoids this.

Similar if OS decides to shedule a different process between getting the total elu from start and the diff elu showing the spin loop the check to verify that total active time is long then the spin loop
fails.
Exchanging these statements avoids this race.

Fixes: #35309

fyi @trevnorris

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
bricss and Trott reacted with thumbs up emoji benjamingr reacted with heart emoji
All reactions
  • 👍 2 reactions
  • ❤️ 1 reaction
@Flarna
test: fix races in test-performance-eventlooputil
b7800f1 
Fix two races in test-performance-eventlooputil resulting in a flaky
test.

elu1 was capture after start time t from spin look. If OS descides to
reschedule the process after capturing t but before getting elu for
>=50ms the spin loop is actually a nop. elu1 doesn't show this and as
a result elut3 = eventLoopUtilization(elu1) results in
elu3.active === 0.
Moving capturing of t after capturing t, just before the spin look
avoids this.

Similar if OS decides to shedule a different process between getting
the total elu from start and the diff elu showing the spin loop the
check to verify that total active time is long then the spin loop
fails.
Exchanging these statements avoids this race.
@nodejs-github-bot nodejs-github-bot added the test Issues and PRs related to Node.js core tests and test infrastructure. label Nov 8, 2020
@Flarna Flarna added the request-ci Add this label to start a Jenkins CI on a PR. Only starts once the PR has an approving review. label Nov 8, 2020
@github-actions github-actions Bot removed the request-ci Add this label to start a Jenkins CI on a PR. Only starts once the PR has an approving review. label Nov 8, 2020
@nodejs-github-bot

nodejs-github-bot commented Nov 8, 2020

Copy link
Copy Markdown
Collaborator

CI: https://ci.nodejs.org/job/node-test-pull-request/34186/
Trott reacted with hooray emoji Flarna reacted with rocket emoji
All reactions
  • 🎉 1 reaction
  • 🚀 1 reaction

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@Flarna Flarna added the author ready PRs with CI started, the required approvals, and no outstanding review comments. label Nov 8, 2020
benjamingr
benjamingr approved these changes Nov 9, 2020
View reviewed changes
@Trott

Trott commented Nov 9, 2020

Copy link
Copy Markdown
Member

Trying to start a stress test for this but CI stress test is not starting for some reason. Anyway, a similar stress test a couple days ago against master showed 12 failures on osx1015 in 1000 runs. So hopefully we can run that on this PR, see that it fixes things, and I can approve this and close my PR to move this test to sequential.
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@Flarna

Flarna commented Nov 9, 2020

Copy link
Copy Markdown
Member Author

@Trott Please note that you refer to a different test (test-worker-eventlooputil) - this PR modifies test-performance-eventlooputil
Trott reacted with thumbs up emoji
All reactions
  • 👍 1 reaction

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@Flarna

Flarna commented Nov 9, 2020

Copy link
Copy Markdown
Member Author

Stress tests:
Master: https://ci.nodejs.org/job/node-stress-single-test/204/ => 3 failures
PR https://ci.nodejs.org/job/node-stress-single-test/203/ => ✔️
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
trevnorris
trevnorris reviewed Nov 9, 2020
View reviewed changes

@trevnorris trevnorris left a comment

Copy link
Copy Markdown
Contributor

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm working on getting the test as it is on my machine to fail from a stress test, but doesn't want to.

Mind checking if moving setting elu1, but not changing anything else, fixes the issue?

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions
Comment thread test/parallel/test-performance-eventlooputil.js

setTimeout(mustCall(function r() {
const t = Date.now();
const elu1 = eventLoopUtilization();

@trevnorris trevnorris Nov 9, 2020 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Contributor

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I messed up here. elu1 also shouldn't be captured until after some idleTime has accumulated. This function call was only meant supposed to check if .active was being set correctly.

The reason for forcing idleTime to accumulate before the test ran was so it would execute the same running it directly or running with ./tools/test.py --worker.

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions
@Flarna

Flarna commented Nov 10, 2020 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member Author

Mind checking if moving setting elu1, but not changing anything else, fixes the issue?

As far as I remember I tried this but then the second race mentioned in description jumped in and resulted in a sporadic fail in the next assert.
The easiest way to get the test failing is to put load on your machine. Start the load generators you like with same prio then the node processes.
To my understaning the elu active time grows also if the process is not scheduled at all as OS assignes no CPU. So another option is to fake this by adding a busy loop between calc of elu2 and elu3 which is the same from elu point of view as not getting a CPU.
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@trevnorris

trevnorris commented Nov 10, 2020

Copy link
Copy Markdown
Contributor

@Flarna Thanks. Was able to reproduce. See what you're saying. I'm testing out some variations w/ you PR. Will get back in a bit.
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@nodejs nodejs deleted a comment from Flarna Nov 10, 2020
trevnorris
trevnorris approved these changes Nov 10, 2020
View reviewed changes

@trevnorris trevnorris left a comment

Copy link
Copy Markdown
Contributor

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Flarna Thanks for the fix. Looks good.

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
All reactions
Trott
Trott approved these changes Nov 10, 2020
View reviewed changes
@Trott

Trott commented Nov 10, 2020

Copy link
Copy Markdown
Member

Landed in 135dd88. Thanks!
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.
@Trott Trott closed this Nov 10, 2020
Trott pushed a commit to Trott/io.js that referenced this pull request Nov 10, 2020
@Flarna @Trott
test: fix races in test-performance-eventlooputil
135dd88 
Fix two races in test-performance-eventlooputil resulting in a flaky
test.

elu1 was capture after start time t from spin look. If OS descides to
reschedule the process after capturing t but before getting elu for
>=50ms the spin loop is actually a nop. elu1 doesn't show this and as
a result elut3 = eventLoopUtilization(elu1) results in
elu3.active === 0.
Moving capturing of t after capturing t, just before the spin look
avoids this.

Similar if OS decides to shedule a different process between getting
the total elu from start and the diff elu showing the spin loop the
check to verify that total active time is long then the spin loop
fails.
Exchanging these statements avoids this race.

PR-URL: nodejs#36028
Fixes: nodejs#35309
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Rich Trott <[email protected]>
@Flarna
Flarna deleted the test-elu-races branch November 10, 2020 14:01
danielleadams pushed a commit that referenced this pull request Nov 10, 2020
@Flarna @danielleadams
test: fix races in test-performance-eventlooputil
fdae9ad 
Fix two races in test-performance-eventlooputil resulting in a flaky
test.

elu1 was capture after start time t from spin look. If OS descides to
reschedule the process after capturing t but before getting elu for
>=50ms the spin loop is actually a nop. elu1 doesn't show this and as
a result elut3 = eventLoopUtilization(elu1) results in
elu3.active === 0.
Moving capturing of t after capturing t, just before the spin look
avoids this.

Similar if OS decides to shedule a different process between getting
the total elu from start and the diff elu showing the spin loop the
check to verify that total active time is long then the spin loop
fails.
Exchanging these statements avoids this race.

PR-URL: #36028
Fixes: #35309
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Rich Trott <[email protected]>
@danielleadams danielleadams mentioned this pull request Nov 10, 2020
v15.2.0 proposal #36055
Merged
richardlau pushed a commit that referenced this pull request Mar 29, 2021
@Flarna @richardlau
test: fix races in test-performance-eventlooputil
364bf03 
Fix two races in test-performance-eventlooputil resulting in a flaky
test.

elu1 was capture after start time t from spin look. If OS descides to
reschedule the process after capturing t but before getting elu for
>=50ms the spin loop is actually a nop. elu1 doesn't show this and as
a result elut3 = eventLoopUtilization(elu1) results in
elu3.active === 0.
Moving capturing of t after capturing t, just before the spin look
avoids this.

Similar if OS decides to shedule a different process between getting
the total elu from start and the diff elu showing the spin loop the
check to verify that total active time is long then the spin loop
fails.
Exchanging these statements avoids this race.

PR-URL: #36028
Fixes: #35309
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Rich Trott <[email protected]>
@richardlau richardlau mentioned this pull request Mar 29, 2021
v12.22.0 proposal #37797
Merged
@richardlau richardlau added the backported-to-v12.x label Mar 29, 2021
targos pushed a commit that referenced this pull request May 1, 2021
@Flarna @targos
test: fix races in test-performance-eventlooputil
2383501 
Fix two races in test-performance-eventlooputil resulting in a flaky
test.

elu1 was capture after start time t from spin look. If OS descides to
reschedule the process after capturing t but before getting elu for
>=50ms the spin loop is actually a nop. elu1 doesn't show this and as
a result elut3 = eventLoopUtilization(elu1) results in
elu3.active === 0.
Moving capturing of t after capturing t, just before the spin look
avoids this.

Similar if OS decides to shedule a different process between getting
the total elu from start and the diff elu showing the spin loop the
check to verify that total active time is long then the spin loop
fails.
Exchanging these statements avoids this race.

PR-URL: #36028
Fixes: #35309
Reviewed-By: Benjamin Gruenbaum <[email protected]>
Reviewed-By: Rich Trott <[email protected]>
@danielleadams danielleadams mentioned this pull request May 3, 2021
v14.17.0 proposal #38507
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@Trott Trott Trott approved these changes
@benjamingr benjamingr benjamingr approved these changes
+1 more reviewer
@trevnorris trevnorris trevnorris approved these changes
Reviewers whose approvals may not affect merge requirements

Uh oh!

There was an error while loading. Please reload this page.

Assignees

No one assigned

Labels

author ready PRs with CI started, the required approvals, and no outstanding review comments. test Issues and PRs related to Node.js core tests and test infrastructure.

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

investigate flaky test-performance-eventlooputil

Uh oh!

There was an error while loading. Please reload this page.

6 participants

@Flarna @nodejs-github-bot @Trott @trevnorris @benjamingr @richardlau
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
You are visitor 01402503 — GeezerVison does not store the pages you look up.
Best viewed with Netscape Navigator 4.7 or Internet Explorer 6 at 800×600. No cookies required.