Skip to content

Instantly share code, notes, and snippets.

@watson
Last active June 24, 2018 17:36
Show Gist options
  • Save watson/f0e88a5ce591db8884dbe4b7ad447528 to your computer and use it in GitHub Desktop.
Save watson/f0e88a5ce591db8884dbe4b7ad447528 to your computer and use it in GitHub Desktop.

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.

@watson
Copy link
Author

watson commented Jun 19, 2018

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

@ThisIsMissEm
Copy link

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.

@ThisIsMissEm
Copy link

@watson
Copy link
Author

watson commented Jun 20, 2018

@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)

@BridgeAR
Copy link

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

@watson
Copy link
Author

watson commented Jun 20, 2018

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

@apapirovski
Copy link

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

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