Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Race conditions between setTimeout() & setImmediate() #48163

Open
ckcr4lyf opened this issue May 25, 2023 · 5 comments
Open

Race conditions between setTimeout() & setImmediate() #48163

ckcr4lyf opened this issue May 25, 2023 · 5 comments
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. linux Issues and PRs related to the Linux platform.

Comments

@ckcr4lyf
Copy link
Contributor

ckcr4lyf commented May 25, 2023

Test

test-timers-immediate-queue.js

Platform

Linux x64

Console output

02:49:14 not ok 2722 parallel/test-timers-immediate-queue
02:49:14   ---
02:49:14   duration_ms: 140.40000
02:49:14   severity: fail
02:49:14   exitcode: 1
02:49:14   stack: |-
02:49:14     hit 20
02:49:14     node:assert:125
02:49:14       throw new AssertionError(obj);
02:49:14       ^
02:49:14     
02:49:14     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
02:49:14     
02:49:14     20 !== 10
02:49:14     
02:49:14         at process.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux/test/parallel/test-timers-immediate-queue.js:56:10)
02:49:14         at process.emit (node:events:523:35) {
02:49:14       generatedMessage: true,
02:49:14       code: 'ERR_ASSERTION',
02:49:14       actual: 20,
02:49:14       expected: 10,
02:49:14       operator: 'strictEqual'
02:49:14     }
02:49:14     
02:49:14     Node.js v21.0.0-pre

Build links

Additional information

This seems to be some kinda potential race condition between setTimeout() and setImmediate() ?

For the following code, it seems TIMEOUT or IMMEDIATE either could be printed first, since over a few runs the order will flip.

setTimeout(() => {
    console.log('TIMEOUT')
}, 1);
setImmediate(() => {
    console.log('IMMEDIATE');
})

However on my machine, the following code will always result in TIMEOUT being printed first - the while loop strategy is what the test uses

setTimeout(() => {
    console.log('TIMEOUT')
}, 1);
const now = Date.now();
while (Date.now() - now < 2);
setImmediate(() => {
    console.log('IMMEDIATE');
})

I was wondering: is it possible due to some conditions on the host system, for IMMEDIATE to print before TIMEOUT in the second case?

I do not know much about the Event Loop internals, but from some rough reading, setTimeout() will put calbacks in the timers queue, setImmediate() in the I/O queue, and the timers are always checked first (https://nodejs.org/en/docs/guides/event-loop-timers-and-nexttick)

But if in the first case (setTimeout without while waiting loop) it is non-predictable, I wonder if there are other factors at play, which make the test flaky.

@ckcr4lyf ckcr4lyf added the flaky-test Issues and PRs related to the tests with unstable failures on the CI. label May 25, 2023
@github-actions github-actions bot added the linux Issues and PRs related to the Linux platform. label May 25, 2023
@ckcr4lyf
Copy link
Contributor Author

Caused failure for #48159

@bnoordhuis
Copy link
Member

The subject issue says setTimeout() & setInterval() but looks like it's really about setTimeout() & setImmediate()?

@ckcr4lyf
Copy link
Contributor Author

Correct, my bad. Let me fix it.

@ckcr4lyf ckcr4lyf changed the title Race conditions between setTimeout() & setInterval() Race conditions between setTimeout() & setImmediate() May 25, 2023
@ywave620
Copy link
Contributor

The timer module only cares about relative time, so node chooses to use gethrtime() as the time source, while the Date.now() is using gettimeofday(). If the clock under the gethrtime() goes enough slower than the one under gettimeofday(), then 'IMMEDIATE' may print first.

setTimeout(() => {
    console.log('TIMEOUT')
}, 1);
const now = Date.now();
while (Date.now() - now < 2);
setImmediate(() => {
    console.log('IMMEDIATE');
})

@ckcr4lyf
Copy link
Contributor Author

Considering the test is testing timers explicitly, would it be better to change it to use process.hrtime() in the now / while condition instead?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. linux Issues and PRs related to the Linux platform.
Projects
None yet
Development

No branches or pull requests

4 participants
@bnoordhuis @ckcr4lyf @ywave620 and others