flaky: parallel/test-timers-immediate-queue

[refack]

• Version: master
• Platform: Windows2016
• Subsystem: timers

Test: test file - parallel/test-timers-immediate-queue
Job: https://ci.nodejs.org/job/node-test-binary-windows/21717/COMPILED_BY=vs2017,RUNNER=win2016,RUN_SUBSET=2/
Worker: https://ci.nodejs.org/computer/test-azure_msft-win2016-x64-6/
Output:

15:49:05 not ok 435 parallel/test-timers-immediate-queue
15:49:05   ---
15:49:05   duration_ms: 0.134
15:49:05   severity: fail
15:49:05   exitcode: 1
15:49:05   stack: |-
15:49:05     hit 40
15:49:05     assert.js:86
15:49:05       throw new AssertionError(obj);
15:49:05       ^
15:49:05     
15:49:05     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
15:49:05     
15:49:05     40 !== 10
15:49:05     
15:49:05         at process.<anonymous> (c:\workspace\node-test-binary-windows\test\parallel\test-timers-immediate-queue.js:56:10)
15:49:05         at process.emit (events.js:194:15)
15:49:05   ...

[refack]

/CC @apapirovski might this be related to #22842?

[Trott]

Attempting to replicate with a stress test: https://ci.nodejs.org/job/node-stress-single-test/2087/

Worker: test-azure_msft-win2016-x64-6

Non-default parameters:

RUN_TESTS: -J --repeat 10 parallel/test-timers-immediate-queue
RUN_TIMES: 100
RUN_LABEL: win2016-1p-vs2017

[apapirovski]

@refack so this is because of timer precision on Windows. I can fix later today. Or someone else could... just needs the timeout and while loop to be bigger than like 16ms or whatever the platform granularity is (can't recall the exact number).

[refack]

FTR stress failed with 49% - 19:59:42 100 OK: 51 NOT OK: 49 TOTAL: 100

Seems like it's fixable via timeGetDevCaps but that's should be a libuv feature.

Ref: https://stackoverflow.com/questions/448761/accurate-windows-timer-system-timers-timer-is-limited-to-15-msec

Anyway, I'm trying to create a test that 100% reproduces so we can add it to known-issues

[Trott]

Seems like it's fixable via timeGetDevCaps but that's libuv feature.

@refack Meaning that it can be fixed in libuv but currently is not?

[refack]

Meaning that it can be fixed in libuv but currently is not?

Yes, exactly.
It might be possible to implement, but complicated to do in a bug-free-cross-platform-compatible way...

[refack]

complicated to do in a bug-free

For example the above mentioned timeGetDevCaps/timeBeginPeriod are (1) global per process 🤷‍♂️ (2) part of the Multimedia API 😕 (3) depend on power (as in electricity) saving profile 🤦‍♂️

IIUC this setting's name is just a coincidence, since it's shared by many other uses of "Multimedia Timers"

[refack]

just needs the timeout and while loop to be bigger than like 16ms

The interwebs say > 15ms, but I'm not sure I grok the test, and know how to change it without eliminating it's essence.

BTW: It doesn't repro on my computer (Windows 10 1809 build 18282)

[Trott]

https://ci.nodejs.org/job/node-test-commit-arm/nodes=centos7-arm64-gcc8/36235/console

06:30:26 not ok 2282 parallel/test-timers-immediate-queue
06:30:26   ---
06:30:26   duration_ms: 0.377
06:30:26   severity: fail
06:30:26   exitcode: 1
06:30:26   stack: |-
06:30:26     hit 90
06:30:26     node:assert:122
06:30:26       throw new AssertionError(obj);
06:30:26       ^
06:30:27     
06:30:27     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
06:30:27     
06:30:27     90 !== 10
06:30:27     
06:30:27         at process.<anonymous> (/home/iojs/build/workspace/node-test-commit-arm/nodes/centos7-arm64-gcc8/test/parallel/test-timers-immediate-queue.js:56:10)
06:30:27         at process.emit (node:events:390:22) {
06:30:27       generatedMessage: true,
06:30:27       code: 'ERR_ASSERTION',
06:30:27       actual: 90,
06:30:27       expected: 10,
06:30:27       operator: 'strictEqual'
06:30:27     }
06:30:27   ...

[Trott]

https://ci.nodejs.org/job/node-test-commit-arm/36447/nodes=centos7-arm64-gcc8/console

00:22:30 not ok 2284 parallel/test-timers-immediate-queue
00:22:30   ---
00:22:30   duration_ms: 0.378
00:22:30   severity: fail
00:22:30   exitcode: 1
00:22:30   stack: |-
00:22:30     hit 30
00:22:30     node:assert:122
00:22:30       throw new AssertionError(obj);
00:22:30       ^
00:22:30     
00:22:30     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
00:22:30     
00:22:30     30 !== 10
00:22:30     
00:22:30         at process.<anonymous> (/home/iojs/build/workspace/node-test-commit-arm/nodes/centos7-arm64-gcc8/test/parallel/test-timers-immediate-queue.js:56:10)
00:22:30         at process.emit (node:events:381:22) {
00:22:30       generatedMessage: true,
00:22:30       code: 'ERR_ASSERTION',
00:22:30       actual: 30,
00:22:30       expected: 10,
00:22:30       operator: 'strictEqual'
00:22:30     }
00:22:30   ...

[Trott]

@nodejs/timers @nodejs/libuv

[Fishrock123]

I'd say revert recent timers commits but everything looks pretty mundane

[Trott]

Closing per #48575