Weird setTimeout "bug" - https://twitter.com/wa7son/status/1009048999972818944

README.md

A setTimeout rabbit hole

setTimeout(function, delay)

docs: https://developer.mozilla.org/en-US/docs/Web/API/WindowOrWorkerGlobalScope/setTimeout

I've always thought that setTimeout would call the function when the delay was up, maybe a little later, but never before.

So if I set a timeout for 10ms, I wouldn't be surprised if it took between 11 or 12ms to complete - in some cases even longer.

But while investigating a weird race condition bug today, I found evidence to suggest that it could in fact take around 9ms to complete.

I've boiled the "bug" down to this test case:

function run () {
  var start = Date.now()
  setTimeout(function () {
    var end = Date.now()
    var diff = end - start
    console.log('diff: %dms', diff)
    if (diff < 10) return console.log('Aborting - found <10ms delay!')
    run()
  }, 10)
}
run()

This fails both in the latest Chrome and in latest Node.js. And before you ask, yes I've also tested this with using process.hrtime() instead of Date.now():

function hrtime () {
  var start = process.hrtime()
  setTimeout(function () {
    var _diff = process.hrtime(start)
    var diff = (_diff[0] * 1e9 + _diff[1]) / 1e6
    console.log('diff: %dms', diff)
    if (diff < 10) return console.log('Aborting - found <10ms delay!')
    hrtime()
  }, 10)
}
hrtime()

Either this is a simpel off-by-one error and I'm just blind, or I've completely misunderstood how setTimeout works and it in fact can call the function earlier, or setTimeout uses a different clock for calculating when it should call the function, or I have discovered a bug in setTimeout (very unlikely).

Here's an example of running the hrtime test on my laptop:

diff: 10.250009ms
diff: 12.856946ms
diff: 12.830893ms
diff: 11.443824ms
diff: 10.190179ms
diff: 12.186512ms
diff: 12.827462ms
diff: 11.329295ms
diff: 12.825859ms
diff: 12.816031ms
diff: 12.409449ms
diff: 12.689547ms
diff: 11.036313ms
diff: 9.249597ms
Aborting - found <10ms delay!

Sometimes it needs to run through 100+ cycles, sometimes it hits the "bug" within 10 cycles. As always, stuff like this is pretty random.

Interesting, thanks. I don't see any evidence though that this should generate negative skew.

If I recall correctly, timers will run in the nearest event loop tick to their expected window. (ncz probably explains it better)

Hence, allowing them to be potentially faster or slower than the interval but a small amount.

See also the docs here: https://nodejs.org/api/timers.html#timers_scheduling_timers

@ThisIsMissEm thank you. I knew there was no guarantee that it would occur exactly on the millisecond, but I thought there were a guarantee that it would never occur before the delay.

The spec says (emphasis mine):

Schedules a timeout to compile and run code after timeout milliseconds.

If that's to be take literally, it sounds like almost all implementations are wrong (Only Safari adheres to this currently of what I have been able to find)

There were a few discussions around this in Node.js and @apapirovski or @Fishrock123 can likely describe the issue best.

Twitter comment thread update: Someone said that it might be due to Spectre timer fuzzing - which it could be - but so far the most plausible explanation is in this thread: https://twitter.com/wanderview/status/1009435974118662144

@watson see nodejs/node#10154 for more info, on the Node.js side anyway.