`setTimeout` can fire early. #5103

Closed
qubyte opened this Issue Mar 21, 2013 · 21 comments

Comments

Projects
None yet
5 participants

qubyte commented Mar 21, 2013

Consider the following code snippet:

var d = Date.now();

setTimeout(function() {
  console.log(Date.now() - d);
}, 2);

According to the the way they are specified by whatwg, setTimeout with a duration below 4ms should fire no sooner than 4ms. Contrary to this, the sample above often fires at 1ms, which is not only below the specified minimum duration, it is below the requested duration.

As I came to Node.js before front end, I hadn't realised that this behaviour was strange until recently. Is this intentional?

This snippet was tested against 0.10.0 and 0.8.4 (versions I have handy) on OS X 10.8.3.

+1

isaacs commented Mar 21, 2013

Our minimum is 1ms. We're not a web browser. It won't fire sooner than the time specified. Doc patch welcome.

isaacs closed this Mar 21, 2013

isaacs commented Mar 21, 2013

Here's a test showing that it does fire no sooner than 2ms in that situation, though: https://gist.github.com/5215350

And if you do some work, it fires early:

https://gist.github.com/bjornstar/5217894

Fails within a second on my windows machine running node v0.10.1

isaacs commented Mar 22, 2013

What kind of system is this that you're running on? Got up to 5000 just fine on OS X, Linux, and SmartOS.

Windows 7 64-bit, i5, 8gb of RAM

Also, your test without doing work fails immediately if I change the setTimeout to 1ms on my Linux system.

isaacs commented Mar 22, 2013

No, I chose 2ms because that's what the op used.

I did see this fail eventually on linux, around the 10000 mark. However, this seems to still be going strong:

var assert = require('assert');

var c = 0;

test();
function test() {
  var d1 = process.hrtime();

  setTimeout(function() {
    var dd = process.hrtime(d1);
    // convert [sec,ns] to msec
    dd = dd[0] * 1e3 + dd[1]/1e6;
    assert(dd >= 2, 'expected at least 2, got ' + dd);
    ++c;
    if (c % 1000 === 0)
      console.log(c);
    var b = {};
    for (var i = 0; i < 100000; i += 1) {
      b[i] = Math.round(Math.random()*400);
    }
    test();
  }, 2);
}

which leads me to suspect that this is simply a lack of precision in the Date.now() function.

qubyte commented Mar 22, 2013

I'm a little confused. What is it about my code snippet that is going wrong? I'm seeing it return 1 about 50% of the time.

What happens if you guys change the ms calculation in those code samples to use proces.hrtime instead? Because yea, it does seem like it may be from sound rounding going on with converting into ms resolution.

Edit: wat, I obviously didn't even read what @isaacs's code was. :facepalm:

qubyte commented Mar 22, 2013

@dougwilson the following code shows the same behaviour:

var d = process.hrtime();

setTimeout(function() {
  var r = process.hrtime(d);
  var result = r[0]*1000 + r[1]/1000000;
  console.log(result);
}, 2);

(I just ran it and got 0.898213.)

@isaacs if you remove the work section from your post and set the timeout to 1 it fails immediately on Mac OS X.

You may be also interested in #4194. Timers definitely can fire earlier than needed.

https://gist.github.com/bjornstar/5218577

This fails on every platform I have tested.

qubyte commented Mar 22, 2013

@AlexeyKupershtokh Thanks! I knew I'd seen something about this before. I just couldn't find the issue. Is it tagged?

@isaacs

Here's a test showing that it does fire no sooner than 2ms in that situation, though: https://gist.github.com/5215350

If you run 2 timers in paralell

test();
test();

It will likely fail sooner or later:

wicked@wicked-desktop:~$ node test.js 
1000
2000
3000
4000

timers.js:103
            if (!process.listeners('uncaughtException').length) throw e;
                                                                      ^
AssertionError: expected at least 2, got 1
    at Object._onTimeout (/home/wicked/test.js:13:5)
    at Timer.list.ontimeout (timers.js:101:19)

qubyte commented Mar 22, 2013

I'm not convinced that timers are not firing early. If anything I'm more convinced that they are, since I've seen more examples of early firing that I didn't code. Can this issue be reopened?

isaacs commented Mar 22, 2013

Yep, indeed, if you do a timeout for 1ms, it fires in less than 1ms.

Reopening.

isaacs reopened this Mar 22, 2013

isaacs commented Mar 22, 2013

This is definitely either a bug in setTimeout, libuv, or hrtime.

@isaacs have you seen PR #4194 that likely fixes the issue?

isaacs commented Mar 24, 2013

Fixed by 9fae4dc (not sure why gh didn't auto-close..)

isaacs closed this Mar 24, 2013

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