Skip to content

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

Closed as not planned
Closed as not planned
Race conditions between setTimeout() & setImmediate()#48163
Labels
flaky-testIssues and PRs involving tests that fail intermittently in CI.linuxIssues and PRs related to the Linux platform.staleIssues and PRs marked stale due to inactivity and scheduled for automatic closure.

Description

@ckcr4lyf
ckcr4lyf
opened on 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.

Activity

  1. ckcr4lyf
    added
    flaky-testIssues and PRs involving tests that fail intermittently in CI.
    on May 25, 2023
  2. github-actions
    added
    linuxIssues and PRs related to the Linux platform.
    on May 25, 2023

  3. ckcr4lyf commented on May 25, 2023

    @ckcr4lyf
    ckcr4lyf
    on May 25, 2023
    ContributorAuthor

    Caused failure for #48159

  4. bnoordhuis commented on May 25, 2023

    @bnoordhuis
    bnoordhuis
    on May 25, 2023
    Member

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

  5. ckcr4lyf commented on May 25, 2023

    @ckcr4lyf
    ckcr4lyf
    on May 25, 2023
    ContributorAuthor

    Correct, my bad. Let me fix it.

  6. ckcr4lyf
    changed the title [-]Race conditions between setTimeout() & setInterval()[/-] [+]Race conditions between setTimeout() & setImmediate()[/+] on May 25, 2023

  7. ywave620 commented on May 27, 2023

    @ywave620
    ywave620
    on May 27, 2023
    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');
})

  8. ckcr4lyf commented on May 27, 2023

    @ckcr4lyf
    ckcr4lyf
    on May 27, 2023
    ContributorAuthor

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

  9. github-actions commented on May 31, 2026

    @github-actions
    github-actionsbot
    on May 31, 2026 – with GitHub Actions
    Contributor

    This issue has been marked as stale due to 210 days of inactivity.
    It will be automatically closed in 30 days if no further activity occurs. If this is still relevant, please leave a comment or update it to keep it open.

  10. github-actions
    added
    staleIssues and PRs marked stale due to inactivity and scheduled for automatic closure.
    on May 31, 2026

  11. github-actions commented on Jul 1, 2026

    @github-actions
    github-actionsbot
    on Jul 1, 2026 – with GitHub Actions
    Contributor

    This issue has been automatically closed after 30 days of inactivity following its stale status (no activity for a total of 240 days).
    If this is still relevant, feel free to reopen it or leave a comment with additional details so we can continue the discussion.

  12. github-actions
    closed this as not plannedon Jul 1, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    flaky-testIssues and PRs involving tests that fail intermittently in CI.linuxIssues and PRs related to the Linux platform.staleIssues and PRs marked stale due to inactivity and scheduled for automatic closure.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions