Tests failing on 0.11+

[STRML]

$ node -v
v0.10.40
$ npm test

> [email protected] test /git/oss/node-toobusy
> mocha tests


  ․․․․․․․․․lag 59 currentLag 19.666666666666664
․lag 56 currentLag 18.666666666666664
․․․․lag 54 currentLag 54
․lag 53 currentLag 2.6500000000000004
lag 53 currentLag 5.1675
lag 53 currentLag 7.559125000000001
lag 53 currentLag 9.83116875
lag 53 currentLag 11.9896103125
lag 53 currentLag 14.040129796875

$ node -v
v0.11.16
$ npm test

> [email protected] test /git/oss/node-toobusy
> mocha tests

child_process: customFds option is deprecated, use stdio instead.

  ․․․․․․․․․lag 15 currentLag 5
lag 102 currentLag 37.333333333333336
․lag 107 currentLag 35.666666666666664
․․․․lag 58 currentLag 58
․lag 55 currentLag 2.75
lag 3 currentLag 2.7624999999999997
lag 57 currentLag 5.474375
lag 0 currentLag 5.20065625
lag 1 currentLag 4.990623437499999
lag 61 currentLag 7.791092265625
lag 3 currentLag 7.55153765234375
․․

  ✖ 2 of 17 tests failed:

  1) smoothingFactor should allow no dampening:
     AssertionError: expected 2 to equal 3

  2) smoothingFactor should respect larger dampening factors:
     Error: timeout of 2000ms exceeded

[STRML]

Real strangeness in the setTimeout(load, 0) that happens at the end of the test.

Node 0.11+ appears to be throttling it based on how cpu-bound it was.

Notice the 100ms delay between ticks, even though nothing is running.

calling tightWork(): start 1456359389295
tightWork(100)
calling tightWork(): end 1456359389395
lag 54 currentLag 9.922725312499999 1456359389395
calling tightWork(): start 1456359389495
tightWork(100)
calling tightWork(): end 1456359389595
lag 5 currentLag 9.676589046874998 1456359389650
calling tightWork(): start 1456359389698
tightWork(100)
calling tightWork(): end 1456359389798
calling tightWork(): start 1456359389898
tightWork(100)
calling tightWork(): end 1456359389998
lag 98 currentLag 14.092759594531248 1456359389998

For comparison, on 0.10:

calling tightWork(): start 1456359447854
tightWork(100)
calling tightWork(): end 1456359447954
calling tightWork(): start 1456359447955
tightWork(100)
calling tightWork(): end 1456359448055
lag 54 currentLag 9.9691625 1456359448055
calling tightWork(): start 1456359448056
tightWork(100)
calling tightWork(): end 1456359448156
calling tightWork(): start 1456359448157
tightWork(100)
calling tightWork(): end 1456359448257
calling tightWork(): start 1456359448258
tightWork(100)
calling tightWork(): end 1456359448358
lag 53 currentLag 12.120704374999999 1456359448358
calling tightWork(): start 1456359448359
tightWork(100)
calling tightWork(): end 1456359448459
calling tightWork(): start 1456359448460
tightWork(100)
calling tightWork(): end 1456359448560

[STRML]

It appears that 0.11 is doing some "smart" delaying of timers that are known to take a certain amount of time so it can better handle them without blocking the event loop. Or maybe this is a bug in core. Reminding myself to look into this for latter. setImmediate() brings back the 0.10 semantics.