setTimeout callback order isn't guaranteed

[sam-github]

• Version: 8.0.0, master
• Platform: Linux samtu 4.8.0-53-generic fs: fix fd leak in ReadStream.destroy() #56-Ubuntu SMP Tue May 16 00:23:44 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
• Subsystem: timers

Perhaps I expect too much, but I expect a sequence of

setTimeout(100, a)
setTimeout(100, b)

to always call a before b, but this doesn't happen. I was looking at this because @hhellyer pointed out that unrefed and refed timers use different timer handles (expected), so I looked, and see that they are in two lists, however, the lists are internally designed so that new callbacks for the same time are appended to a list, guaranteeing order, but it isn't clear that those ordering guarantees are maintained across refed and unrefed timers, since they use different lists.

Or, perhaps I'm seeing an artifact of timer accuracy?

@Fishrock123 @mscdex You two seem familiar with the timers, what do you think, is this a problem?

_.js

function F(s) {
  return () => console.log(s);
}

setTimeout(F('A'), 100)
setTimeout(F('B'), 100).unref()
setTimeout(F('C'), 100)
setTimeout(F('D'), 100).unref()

Output:

% ./node -v
v9.0.0-pre
% ./node _.js
A
C
B
D
% node -v
v8.0.0
% node _.js
A
B
D
C
% node _.js
A
C
B
D
% node _.js
A
C
B
D
core/node (check-is-listening $%) % node -v
v8.0.0

[sam-github]

#1271 suggests timers out of order is considered a bug (thanks to @gibfahn for finding that)

[Trott]

#1271 suggests timers out of order is considered a bug (thanks to @gibfahn for finding that)

@sam-github Interesting. Node.js docs for setTimeout() say (emphasis added):

Node.js makes no guarantees about the exact timing of when callbacks will fire, nor of their ordering.

That's not necessarily to say you're wrong to expect what you expect or that it shouldn't be fixed. Just providing context for observers and participants.

[sam-github]

exact timing is expected fallout from the nature of OSes and runtimes, but the ordering statement surprises me, and seems to contradict https://github.com/nodejs/node/blob/master/lib/timers.js#L109-L110

[Trott]

To save folks a click, here's the code comment @sam-github highlighted:

Therefore, any timer added later will always have been scheduled to
timeout later, thus only needing to be appended.

I'm not sure it contradicts the statement in the docs. Scheduling and actual execution may be separate things (although obviously related).

One thing is for sure: The observed behavior conforms with the non-guarantee in the docs. :-D

[Trott]

/cc @misterdjules

[sam-github]

I read that comment as "scheduled" meaning "setTimeout was called", and the list will be processed (aka executed) from front to back, so its saying since the setTimeout() call that scheduled this callback is occuring later than all the setTimeouts that scheduled the callbacks already in the list, its always safe to just append the callback, execution order will remain that of scheduling order.

Yes, I might be reading a lot into that, maybe scheduling means something else.

[sam-github]

This is interesting, for next tick, according to the docs, we can call the callbacks in any order, LIFO, FIFO, random (though the docs don't call that out as they do for setTimeout, they just don't mention that they will be called in FIFO order).

Once the current turn of the event loop turn runs to completion, all callbacks currently in the next tick queue will be called.

• https://nodejs.org/api/process.html#process_process_nexttick_callback_args

[misterdjules]

the ordering statement surprises me, and seems to contradict https://github.com/nodejs/node/blob/master/lib/timers.js#L109-L110

I read "Therefore, any timer added later will always have been scheduled to timeout later" as "any timer added later to a given TimersList will always have been scheduled to timeout later".

As was pointed out in the original post, timer instances on which the unref() method is called are not in a TimersList anymore, and so this statement doesn't apply to them.

EDIT: In other words, this is more a comment describing an implementation detail of why using the current data structure has some desirable properties rather than describing a given behavior that users can rely on.

Whether that's a problem is a different question, but as was mentioned above, this seems to be consistent with the documentation.

[Fishrock123]

Some fundamentals:

Yes, we do not state in the docs that timer order is deterministic. (In both Node and Libuv.) This is mostly to ensure we have more freedom to tweak the underlying implementation, as I understand. Perhaps we are now at a stable enough point that we can document the specifics of the determinism.

I'm not 100% sure if there are holes in the determinism, but:

• libuv's binary heap should always keep timer handles in order, and also return the callbacks in order.
• Timers in any one Node.js TimersList are guaranteed to execute in that order.
• In combination, timer ordering should be deterministic (not including unrefed timers or native add-ons).

That being said, since an unrefed list (or single unrefed timer) has a separate handle (but still the same duration) I think the order in libuv may depend on the order of operations done to the timers. Perhaps there is something unexpected hiding there.

---

#1271 was fixed.

---

In other words, this is more a comment describing an implementation detail of why using the current data structure has some desirable properties rather than describing a given behavior that users can rely on.

Correct, since the position at the point (and probably today) is that we haven't explicitly guaranteed that.

Although I think that may not be a bad idea at this point.

[Fishrock123]

In regards to the OP, the following is deterministic:

setTimeout(100, a)
setTimeout(100, b)

With no further modification, a will always be called before b.

@sam-github could you post more of your code? Do you have unrefed timers somewhere or are you depending on the timing of internal Socket timers?

[sam-github]

@Fishrock123 the entirety of my code is in the issue description, and yes, there are unrefed timers (the effect of unrefing of timers is explicitly what I was exploring).

FYI, I don't mind if this is closed, or just documented that there are effectively two timer lists and callback ordering is deterministic only within a list. IMO, ideally, an implementation could be found that would cause unrefing/refing to not cause changes in callback order, but that may be difficult to do without losing performance, and performance is more important.

[Fishrock123]

@sam-github of note, I do not think the following order is possible:

A
B
D
C

C will always come directly after A. I'm not sure if there are any other restrictions on where B and D will be ordered or not.

[Fishrock123]

Also, I think the alternate implementation described in #8372 (comment) would fix this. I don't have time to do that though and it is hard to know if it would be worth it.

[sam-github]

@Fishrock123 that order is possible, determined experimentally, see the bug report.

% node -v
v8.0.0
% node _.js
A
B
D
C

I've no comment on why its possible, but its what I saw.

[Fishrock123]

@sam-github Odd. Perhaps there is a platform-dependant bug here?

I only ever get this, which would seem to be the "correct" output.

A
C
B
D

Could you try forcing process.stdout._handle.setBlocking(true)? (Should be the default...)
Perhaps your terminal is async/interleaving. (Seems likely?)

[misterdjules]

The following:

% node _.js
A
B
D
C

can happen because, since C is in second position in the TimersList of timers with a delay of 100, it is re-scheduled at least once, and that rescheduling (the call to uv_timer_start) happens after D was already scheduled.

That means that C's underlying libuv timer will have a start_id > to D's underlying libuv timer.

As a result, when D is scheduled to be due at the same time as C (which depends on the time it takes for setTimeout(F('C'), 100) to run, in that case scheduling C and D must happen within the same millisecond), the tie is broken between them using that start_id. D wins and is thus picked first to fire.

[Fishrock123]

can happen because, since C is in second position in the TimersList of timers with a delay of 100, it is re-scheduled at least once,

It shouldn't be rescheduled though? Both A & C should be diff < msecs, I think. I suppose the _idleStart of one of the timers could be greater, but I don't think I've ever encountered that?

[misterdjules]

I think. I suppose the _idleStart of one of the timers could be greater, but I don't think I've ever encountered that?

This is what is sometimes happening. The _idleStart of C will be different than the _idleStart of A, unless scheduling A, B and C happens in the same millisecond.

[sam-github]

So, to summarize final state:

1. no one is greatly perturbed that timers are ordered only with respect to other timeouts of the same "ref/unref state", and this behaviour associated with refing/unrefing timers doesn't seem to have caused problems, even though its easily observable
2. some effort has been made to make sure timers on the same list fire in the sequence of the setTimeout() calls (all other things being equal), but we have not yet been comfortable documenting this
3. as a possible optimization (by minimizing uv timers), timer_t usage could be minimized by keeping refed and unrefed timers on the same list in association with a manually maintained count of refed timers. TBD, not an emergency.

Perhaps we should document (2), but I'm closing this as wontfix, and perhaps someone will have time to work on the optimization some time.

[misterdjules]

That seems like a great summary @sam-github.

[Fishrock123]

I suppose I always thought that (1) was implied. Although that really isn't clear.

I think we could probably document (2). More than just "some" effort has been put in to that. It may however require documenting more internal structure and not be worth it? Honestly, most good timers algos guarantee this, so I don't think that is a big risk or anything.

(3) could probably be picked up by anyone at some point but we may need to create a summary issue that people can better understand and tackle.