Skip to content

investigate flaky test-timers-blocking-callback #21781

Closed
Closed
investigate flaky test-timers-blocking-callback#21781
Assignees
apapirovski
Labels
flaky-testIssues and PRs involving tests that fail intermittently in CI.macosIssues and PRs related to the macOS platform.timersIssues and PRs related to timers, setImmediate(), setInterval(), and setTimeout().

Description

@Trott
Trott
opened on Jul 12, 2018
  • Version: 11.0.0-pre (master)
  • Platform: osx1012
  • Subsystem: test timers

https://ci.nodejs.org/job/node-test-commit-osx/19771/nodes=osx1012/console

13:09:28 not ok 2336 sequential/test-timers-blocking-callback
13:09:28   ---
13:09:28   duration_ms: 2.270
13:09:28   severity: fail
13:09:28   exitcode: 1
13:09:28   stack: |-
13:09:28     assert.js:80
13:09:28       throw new AssertionError(obj);
13:09:28       ^
13:09:28     
13:09:28     AssertionError [ERR_ASSERTION]: timeout delayed by more than 100% (230ms)
13:09:28         at blockingCallback (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1012/test/sequential/test-timers-blocking-callback.js:62:14)
13:09:28         at ontimeout (timers.js:457:11)
13:09:28         at tryOnTimeout (timers.js:327:5)
13:09:28         at listOnTimeout (timers.js:301:5)
13:09:28         at processTimers (timers.js:258:5)
13:09:28   ...

Activity

  1. Trott
    added
    timersIssues and PRs related to timers, setImmediate(), setInterval(), and setTimeout().
    macosIssues and PRs related to the macOS platform.
    flaky-testIssues and PRs involving tests that fail intermittently in CI.
    on Jul 12, 2018
  2. apapirovski
    self-assigned this
    on Jul 13, 2018

  3. Trott commented on Jul 15, 2018

    @Trott
    Trott
    on Jul 15, 2018
    MemberAuthor

    Happened again today.

    https://ci.nodejs.org/job/node-test-commit-osx/nodes=osx1012/19834/console

    20:24:08 not ok 2340 sequential/test-timers-blocking-callback
20:24:08   ---
20:24:08   duration_ms: 2.301
20:24:08   severity: fail
20:24:08   exitcode: 1
20:24:08   stack: |-
20:24:08     assert.js:80
20:24:08       throw new AssertionError(obj);
20:24:08       ^
20:24:08     
20:24:08     AssertionError [ERR_ASSERTION]: timeout delayed by more than 100% (250ms)
20:24:08         at blockingCallback (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1012/test/sequential/test-timers-blocking-callback.js:62:14)
20:24:08         at ontimeout (timers.js:457:11)
20:24:08         at tryOnTimeout (timers.js:327:5)
20:24:08         at listOnTimeout (timers.js:301:5)
20:24:08         at processTimers (timers.js:258:5)
20:24:08   ...

  4. apapirovski commented on Jul 15, 2018

    @apapirovski
    apapirovski
    on Jul 15, 2018
    Contributor

    @Trott Given that this only fails on macOS 10.12, I wonder if there's either something weird about the setup of that system or a bug in the OS itself. FWIW I'm on 10.12.6 and can't get this test to fail even in parallel with -j 96 --repeat 960.

    Also, the duration of the run when it fails (2.3s) indicates that something weird is happening on that machine. This test normally takes significantly less time.

  5. Trott commented on Jul 15, 2018

    @Trott
    Trott
    on Jul 15, 2018
    MemberAuthor

    @apapirovski For what it's worth, since the test is in sequential, the -j 96 won't really affect it. If you want to test under load, move it to parallel and run that version with -j 96 --repeat 960 (or whatever).

  6. apapirovski commented on Jul 16, 2018

    @apapirovski
    apapirovski
    on Jul 16, 2018
    Contributor

    @Trott yes, that is what I did to test it.

  7. Trott commented on Jul 16, 2018

    @Trott
    Trott
    on Jul 16, 2018
    MemberAuthor

    @Trott yes, that is what I did to test it.

    Oooooohhhhhh...yeah, in that case...I'm not seeing it fail that way either, so this is probably something other than mere load (like maybe one of the two possibilities you suggest, of course)

  8. Trott commented on Jul 30, 2018

    @Trott
    Trott
    on Jul 30, 2018
    MemberAuthor

    Again today: https://ci.nodejs.org/job/node-test-commit-osx/20095/nodes=osx1012/console

    04:20:50 not ok 2354 sequential/test-timers-blocking-callback
04:20:50   ---
04:20:50   duration_ms: 1.755
04:20:50   severity: fail
04:20:50   exitcode: 1
04:20:50   stack: |-
04:20:50     assert.js:84
04:20:50       throw new AssertionError(obj);
04:20:50       ^
04:20:50     
04:20:50     AssertionError [ERR_ASSERTION]: timeout delayed by more than 100% (250ms)
04:20:50         at blockingCallback (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1012/test/sequential/test-timers-blocking-callback.js:62:14)
04:20:50         at ontimeout (timers.js:454:11)
04:20:50         at tryOnTimeout (timers.js:326:5)
04:20:50         at listOnTimeout (timers.js:300:5)
04:20:50         at processTimers (timers.js:257:5)
04:20:50   ...

  9. Trott commented on Jul 30, 2018

    @Trott
    Trott
    on Jul 30, 2018
    MemberAuthor

    FWIW, the 10.12 machines in CI are relatively small machines (I believe 3GHz 2-core 4GB RAM) so maybe that's part of what's going on?

  10. Trott commented on Jul 30, 2018

    @Trott
    Trott
    on Jul 30, 2018
    MemberAuthor

    @nodejs/platform-macos

  11. apapirovski commented on Jul 31, 2018

    @apapirovski
    apapirovski
    on Jul 31, 2018
    Contributor

    I'm still completely stumped by this. I might have to request access to one of these machines to make further progress.

  12. Fishrock123 commented on Aug 7, 2018

    @Fishrock123
    Fishrock123
    on Aug 7, 2018
    Contributor

    I'm not sure either.

    That being said, with the most recent timers refactor, is this test still relevant?

  13. apapirovski commented on Aug 7, 2018

    @apapirovski
    apapirovski
    on Aug 7, 2018
    Contributor

    @Fishrock123 not super relevant but probably worth keeping around depending on how the architecture evolves, right? I'll try to get access later this week and see what's going on.

  14. 7 remaining items

  15. Fishrock123 commented on Apr 12, 2020

    @Fishrock123
    Fishrock123
    on Apr 12, 2020
    Contributor

    Also, does this always happen on macOs 10.15 now?

  16. targos
    added a commit that references this issue on Apr 22, 2020

    test: mark test-timers-blocking-callback flaky on osx

    0403f00
  17. Fishrock123
    added a commit that references this issue on Apr 25, 2020

    test: remove timers-blocking-callback

    2d10f13

  18. Trott commented on Apr 26, 2020

    @Trott
    Trott
    on Apr 26, 2020
    MemberAuthor

    Fixed in f8d5474

  19. Trott
    closed this as completedon Apr 26, 2020
  20. Trott
    added a commit that references this issue on Apr 26, 2020

    test: remove timers-blocking-callback

    f8d5474
  21. BethGriggs
    added a commit that references this issue on Apr 27, 2020

    test: remove timers-blocking-callback

    242dfdd
  22. BridgeAR
    added 2 commits that reference this issue on Apr 28, 2020

    test: remove timers-blocking-callback

    5bdb401

    test: remove timers-blocking-callback

    790c453
  23. BethGriggs
    added a commit that references this issue on Apr 28, 2020

    test: remove timers-blocking-callback

    8fad112
  24. targos
    added a commit that references this issue on Apr 30, 2020

    test: remove timers-blocking-callback

    71fa8d7
  25. targos
    added a commit that references this issue on May 13, 2020

    test: remove timers-blocking-callback

    8352045
  26. richardlau
    added a commit that references this issue on Jul 15, 2020

    test: remove timers-blocking-callback

    7a109fe
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

flaky-testIssues and PRs involving tests that fail intermittently in CI.macosIssues and PRs related to the macOS platform.timersIssues and PRs related to timers, setImmediate(), setInterval(), and setTimeout().

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions