Skip to content

Instantly share code, notes, and snippets.

@watson
Last active June 24, 2018 17:36
Show Gist options
  • Star 3 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • 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.

@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