timers: fix setTimeout expiration logic #24214

suguru03 · 2018-11-07T06:06:01Z

I fixed the setTimeout issue.
I changed the logic to be the same logic as v10.30.0 following the lines. https://github.com/nodejs/node/blob/v10.13.0/lib/timers.js#L240-L243

Fixes: #24203

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
commit message follows commit guidelines

addaleax · 2018-11-07T12:47:53Z

/cc @nodejs/timers

addaleax · 2018-11-07T12:48:38Z

CI: https://ci.nodejs.org/job/node-test-pull-request/18402/

benjamingr · 2018-11-07T14:37:18Z

lib/timers.js

      list.expiry = timer._idleStart + msecs;
+      if (list.expiry <= prev)
+        list.expiry++;


Can you please add a comment here explaining this is done to avoid floating point rounding errors? It's clear in the context of this PR but less so when seen in isolation.

Sure, but it is a little difficult to explain just a few lines for me.. I would like you to help it.

node/lib/timers.js

Lines 206 to 207 in af6d262

const expiry = start + msecs;

lists[msecs] = list = new TimersList(expiry, msecs);

const msecs = 1.00000000000001; console.log(126 + msecs); // 127.00000000000001 console.log(127 + msecs); // 128

In this case, when start is turning to 127, floating point precison is changed. So it will be integer.

Then,

node/lib/timers.js

Lines 259 to 263 in af6d262

while (list = queue.peek()) {

if (list.expiry > now) {

nextExpiry = list.expiry;

return refCount > 0 ? nextExpiry : -nextExpiry;

}

when now is 128, it will be false.

After that, listOnTimeout will be called and check the differences here.

node/lib/timers.js

Lines 285 to 288 in af6d262

if (diff < msecs) {

list.expiry = timer._idleStart + msecs;

list.id = timerListId++;

queue.percolateDown(1);

In this time, the diff will be 1 but msecs is 1.00000000000001.
So the if state will be true and queue.percolateDown(1) will be called.
Finally, the list will be peeked and goes into an infinite loop .

I could change list.expiry > now to list.expiry >= now, but I'm afraid it may break something else.

benjamingr

Thank you 🙏

benjamingr · 2018-11-07T14:38:28Z

Also @suguru03 nice seeing you around, thanks for the patch and hope you stick around and collaborate some more :)

If you have any questions about the collaboration process please let us know and we'll do our best to answer them.

suguru03 · 2018-11-07T20:33:28Z

@benjamingr Thank you very much for the comment, I really appreciate it!
I will contribute more if there is any chance. 😄

Fishrock123 · 2018-11-07T20:35:53Z

Uh, floating point / decimal numbers should be rounded to an integer IIRC.

Are you saying that no longer happens on Node 11?

suguru03 · 2018-11-07T21:49:47Z

@Fishrock123
I also checked this line on Node 10, but it seems not to be rounded.

node/lib/timers.js

Line 228 in ab4af08

const msecs = list.msecs;

https://github.com/nodejs/node/blob/v10.13.0/lib/timers.js#L228

apapirovski · 2018-11-09T06:53:42Z

Uh, floating point / decimal numbers should be rounded to an integer IIRC.

They're not. They probably should be. That's likely a better fix for this issue. (Previously this only really worked because of implicit conversion when creating handles.)

Edit: not sure it's actually a better fix after thinking about it.

apapirovski

Small change that I think makes this easier to understand but other than that LGTM. Thank you for fixing!

apapirovski · 2018-11-09T15:44:29Z

lib/timers.js

@@ -283,7 +283,10 @@ function listOnTimeout(list, now) {
    // Check if this loop iteration is too early for the next timer.
    // This happens if there are more timers scheduled for later in the list.
    if (diff < msecs) {
+      const prev = list.expiry;


I think this can all be replaced by list.expiry = Math.max(timer._idleStart + msecs, now + 1);

Thanks for the review!
I'll fix it 😄

TimothyGu · 2018-11-09T22:15:16Z

I agree with @Fishrock123 that converting to integer _when setTimeout() is called would be a better fix. It would also agree with browsers. Specifically,

https://github.com/nodejs/node/blob/f6703a007d921a6bb5cda7325a6a0228453500c8/lib/internal/timers.js#L57

would probably instead be ~~after |= 0~~ after = Math.trunc(after).

suguru03 · 2018-11-10T03:41:21Z

@TimothyGu Thanks for the comment!
I agree to convert it to an integer there.
But I'm not sure if I should use Math.trunc, because the current behaviour is like Math.ceil.

Also, it is for fixing the bug, I think it is better to keep the current handling.
If I need to change it on this PR, I will do it. I will follow the members' decision. 🙂

Trott · 2018-11-14T08:03:20Z

So, uh, should this land as-is to fix the bug and then someone can submit a PR to align more with browsers, truncate/floor instead of ceil, etc.? Or should those fixes happen here and now?

My opinion: This has been quiet for 4 days, and it would be nice to get the bug fixed. So I'm inclined to land this or to suggest that anyone who thinks it should be different should get in there and change it and push a second commit to this branch. Thoughts?

In the meantime, CI: https://ci.nodejs.org/job/node-test-pull-request/18608/

suguru03 · 2018-11-16T18:32:17Z

I rebased onto the latest master.

@apapirovski If I need to change the logic on this PR, please let me know 😄

Fix the timer logic to be the same as v10.30.0. Fixes: nodejs#24203

apapirovski · 2018-11-20T16:42:15Z

@Trott this should just land as is. I'll land later today if no one else does.

Trott · 2018-11-25T18:13:32Z

@Trott this should just land as is. I'll land later today if no one else does.

Unfortunately, CI is locked down right now and changes have been force-pushed since the last CI run, so this will have to wait until the release on Tuesday....

suguru03 · 2018-11-28T18:33:08Z

@Trott Thanks for the update!
If I need to do something, please let me know. 🙂

Trott · 2018-11-30T03:27:25Z

CI: https://ci.nodejs.org/job/node-test-pull-request/19073/

Trott · 2018-12-01T04:15:07Z

Resume Build CI: https://ci.nodejs.org/job/node-test-pull-request/19104/

Fishrock123

I’ll follow up separately with the other ideal changes

Trott · 2018-12-01T06:20:52Z

Resume Build again: https://ci.nodejs.org/job/node-test-pull-request/19113/

Trott · 2018-12-01T15:31:44Z

I've taken the problematic ubuntu1804-64 host offline so hopefully we get a non-problematic one this time.

Resume Build CI: https://ci.nodejs.org/job/node-test-pull-request/19119/

Fix the timer logic to be the same as v10.30.0. Fixes: nodejs#24203 PR-URL: nodejs#24214 Reviewed-By: Benjamin Gruenbaum <[email protected]> Reviewed-By: Gus Caplan <[email protected]> Reviewed-By: Anatoli Papirovski <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Jeremiah Senkpiel <[email protected]>

Trott · 2018-12-01T16:21:07Z

Landed in e9de435.

Thanks for the contribution! 🎉

suguru03 · 2018-12-02T02:15:36Z

@Trott Thank you very much! 😄

Fix the timer logic to be the same as v10.30.0. Fixes: #24203 PR-URL: #24214 Reviewed-By: Benjamin Gruenbaum <[email protected]> Reviewed-By: Gus Caplan <[email protected]> Reviewed-By: Anatoli Papirovski <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Jeremiah Senkpiel <[email protected]>

Fix the timer logic to be the same as v10.30.0. Fixes: nodejs#24203 PR-URL: nodejs#24214 Reviewed-By: Benjamin Gruenbaum <[email protected]> Reviewed-By: Gus Caplan <[email protected]> Reviewed-By: Anatoli Papirovski <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Jeremiah Senkpiel <[email protected]>

Reverts some timers behavior back to as it was before 2930bd1 That commit introduced an unintended change which allowed non-integer timeouts to actually exist since the value is no longer converted to an integer via a TimeWrap handle directly. Even with the fix in e9de435 non-integer timeouts are still indeterministic, because libuv does not support them. This fixes the issue by emulating the old behavior: truncate the `_idleTimeout` before using it. See comments in nodejs#24214 for more background on this.

Reverts some timers behavior back to as it was before 2930bd1 That commit introduced an unintended change which allowed non-integer timeouts to actually exist since the value is no longer converted to an integer via a TimeWrap handle directly. Even with the fix in e9de435 non-integer timeouts are still indeterministic, because libuv does not support them. This fixes the issue by emulating the old behavior: truncate the `_idleTimeout` before using it. See comments in #24214 for more background on this. PR-URL: #24819 Reviewed-By: Anatoli Papirovski <[email protected]> Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Ruben Bridgewater <[email protected]> Reviewed-By: Trivikram Kamat <[email protected]> Reviewed-By: James M Snell <[email protected]>

addaleax requested a review from apapirovski November 7, 2018 12:47

addaleax added the timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. label Nov 7, 2018

benjamingr reviewed Nov 7, 2018

View reviewed changes

benjamingr approved these changes Nov 7, 2018

View reviewed changes

devsnek approved these changes Nov 7, 2018

View reviewed changes

Fishrock123 self-requested a review November 7, 2018 20:37

apapirovski approved these changes Nov 9, 2018

View reviewed changes

suguru03 force-pushed the fix-timer branch from 21d98bc to f6703a0 Compare November 9, 2018 19:28

apapirovski approved these changes Nov 9, 2018

View reviewed changes

suguru03 force-pushed the fix-timer branch from f6703a0 to 3422c73 Compare November 16, 2018 18:29

suguru03 force-pushed the fix-timer branch 2 times, most recently from 8a4aff1 to f0e35ff Compare November 16, 2018 21:05

timers: fix setTimeout expiration logic

80dcd9f

Fix the timer logic to be the same as v10.30.0. Fixes: nodejs#24203

suguru03 force-pushed the fix-timer branch from f0e35ff to 80dcd9f Compare November 16, 2018 21:52

jasnell approved these changes Nov 21, 2018

View reviewed changes

Fishrock123 approved these changes Dec 1, 2018

View reviewed changes

Trott closed this Dec 1, 2018

suguru03 deleted the fix-timer branch December 2, 2018 02:15

Fishrock123 mentioned this pull request Dec 4, 2018

timers: truncate decimal values #24819

Closed

4 tasks

BridgeAR mentioned this pull request Dec 5, 2018

v11.4.0 proposal #24854

Merged

4 tasks

targos mentioned this pull request Dec 7, 2018

setTimeout eating CPU time and doing infinity stuck with non-whole delay #24897

Closed

BethGriggs added the dont-land-on-v10.x label Jun 25, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

timers: fix setTimeout expiration logic #24214

timers: fix setTimeout expiration logic #24214

suguru03 commented Nov 7, 2018

addaleax commented Nov 7, 2018

addaleax commented Nov 7, 2018

benjamingr Nov 7, 2018

suguru03 Nov 7, 2018

benjamingr left a comment

benjamingr commented Nov 7, 2018

suguru03 commented Nov 7, 2018

Fishrock123 commented Nov 7, 2018

suguru03 commented Nov 7, 2018

apapirovski commented Nov 9, 2018 •

edited

Loading

apapirovski left a comment •

edited

Loading

apapirovski Nov 9, 2018

suguru03 Nov 9, 2018

TimothyGu commented Nov 9, 2018 •

edited

Loading

suguru03 commented Nov 10, 2018

Trott commented Nov 14, 2018

suguru03 commented Nov 16, 2018

apapirovski commented Nov 20, 2018

Trott commented Nov 25, 2018

suguru03 commented Nov 28, 2018

Trott commented Nov 30, 2018

Trott commented Dec 1, 2018

Fishrock123 left a comment

Trott commented Dec 1, 2018

Trott commented Dec 1, 2018

Trott commented Dec 1, 2018

suguru03 commented Dec 2, 2018

	const expiry = start + msecs;
	lists[msecs] = list = new TimersList(expiry, msecs);

	while (list = queue.peek()) {
	if (list.expiry > now) {
	nextExpiry = list.expiry;
	return refCount > 0 ? nextExpiry : -nextExpiry;
	}

	if (diff < msecs) {
	list.expiry = timer._idleStart + msecs;
	list.id = timerListId++;
	queue.percolateDown(1);

timers: fix setTimeout expiration logic #24214

timers: fix setTimeout expiration logic #24214

Conversation

suguru03 commented Nov 7, 2018

Checklist

addaleax commented Nov 7, 2018

addaleax commented Nov 7, 2018

benjamingr Nov 7, 2018

Choose a reason for hiding this comment

suguru03 Nov 7, 2018

Choose a reason for hiding this comment

benjamingr left a comment

Choose a reason for hiding this comment

benjamingr commented Nov 7, 2018

suguru03 commented Nov 7, 2018

Fishrock123 commented Nov 7, 2018

suguru03 commented Nov 7, 2018

apapirovski commented Nov 9, 2018 • edited Loading

apapirovski left a comment • edited Loading

Choose a reason for hiding this comment

apapirovski Nov 9, 2018

Choose a reason for hiding this comment

suguru03 Nov 9, 2018

Choose a reason for hiding this comment

TimothyGu commented Nov 9, 2018 • edited Loading

suguru03 commented Nov 10, 2018

Trott commented Nov 14, 2018

suguru03 commented Nov 16, 2018

apapirovski commented Nov 20, 2018

Trott commented Nov 25, 2018

suguru03 commented Nov 28, 2018

Trott commented Nov 30, 2018

Trott commented Dec 1, 2018

Fishrock123 left a comment

Choose a reason for hiding this comment

Trott commented Dec 1, 2018

Trott commented Dec 1, 2018

Trott commented Dec 1, 2018

suguru03 commented Dec 2, 2018

apapirovski commented Nov 9, 2018 •

edited

Loading

apapirovski left a comment •

edited

Loading

TimothyGu commented Nov 9, 2018 •

edited

Loading