timers: backport f8193ab

Original commit message:

 timers: use uv_now instead of Date.now

 This saves a few calls to gettimeofday which can be expensive, and
 potentially subject to clock drift. Instead use the loop time which
 uses hrtime internally.

In addition to the backport, this commit:
 - keeps _idleStart timers' property which is still set to
   Date.now() to avoid breaking existing code that uses it, even if
   its use is discouraged.
 - adds automated tests. These tests use a specific branch of
   libfaketime that hasn't been submitted upstream yet. libfaketime
   is git cloned if needed when running automated tests.

Signed-off-by: Timothy J Fontaine <tjfontaine@gmail.com>

.gitignore

@@ -57,3 +57,6 @@ deps/openssl/openssl.xml
 /SHASUMS*.txt*
 
 /tools/wrk/wrk
+
+# test artifacts
+tools/faketime

Makefile

@@ -125,6 +125,13 @@ test-npm: node
 test-npm-publish: node
 	npm_package_config_publishtest=true ./node deps/npm/test/run.js
 
+test-timers:
+	$(MAKE) --directory=tools faketime
+	$(PYTHON) tools/test.py --mode=release timers
+
+test-timers-clean:
+	$(MAKE) --directory=tools clean
+
 apidoc_sources = $(wildcard doc/api/*.markdown)
 apidocs = $(addprefix out/,$(apidoc_sources:.markdown=.html)) \
           $(addprefix out/,$(apidoc_sources:.markdown=.json))

lib/timers.js

@@ -51,6 +51,8 @@ var lists = {};
 // with them.
 function insert(item, msecs) {
   item._idleStart = Date.now();
+  item._monotonicStartTime = Timer.now();
+
   item._idleTimeout = msecs;
 
   if (msecs < 0) return;
@@ -80,12 +82,12 @@ function listOnTimeout() {
 
   debug('timeout callback ' + msecs);
 
-  var now = Date.now();
+  var now = Timer.now();
   debug('now: ' + now);
 
   var first;
   while (first = L.peek(list)) {
-    var diff = now - first._idleStart;
+    var diff = now - first._monotonicStartTime;
     if (diff < msecs) {
       list.start(msecs - diff, 0);
       debug(msecs + ' list wait because diff is ' + diff);
@@ -177,6 +179,7 @@ exports.active = function(item) {
       insert(item, msecs);
     } else {
       item._idleStart = Date.now();
+      item._monotonicStartTime = Timer.now();
       L.append(list, item);
     }
   }
@@ -282,15 +285,21 @@ var Timeout = function(after) {
   this._idlePrev = this;
   this._idleNext = this;
   this._idleStart = null;
+  this._monotonicStartTime = null;
   this._onTimeout = null;
   this._repeat = false;
 };
 
 Timeout.prototype.unref = function() {
   if (!this._handle) {
-    var now = Date.now();
+
-    if (!this._idleStart) this._idleStart = now;
+    var nowMonotonic = Timer.now();
-    var delay = this._idleStart + this._idleTimeout - now;
+    if (!this._idleStart || !this._monotonicStartTime) {
+      this._idleStart = Date.now();
+      this._monotonicStartTime = nowMonotonic;
+    }
+
+    var delay = this._monotonicStartTime + this._idleTimeout - nowMonotonic;
     if (delay < 0) delay = 0;
     exports.unenroll(this);
     this._handle = new Timer();
@@ -388,13 +397,13 @@ var unrefList, unrefTimer;
 
 
 function unrefTimeout() {
-  var now = Date.now();
+  var now = Timer.now();
 
   debug('unrefTimer fired');
 
   var first;
   while (first = L.peek(unrefList)) {
-    var diff = now - first._idleStart;
+    var diff = now - first._monotonicStartTime;
 
     if (diff < first._idleTimeout) {
       diff = first._idleTimeout - diff;
@@ -447,27 +456,30 @@ exports._unrefActive = function(item) {
     unrefTimer.ontimeout = unrefTimeout;
   }
 
-  var now = Date.now();
+  var nowDate = Date.now();
-  item._idleStart = now;
+  var nowMonotonicTimestamp = Timer.now();
+
+  item._idleStart = nowDate;
+  item._monotonicStartTime = nowMonotonicTimestamp;
 
   if (L.isEmpty(unrefList)) {
     debug('unrefList empty');
     L.append(unrefList, item);
 
     unrefTimer.start(msecs, 0);
-    unrefTimer.when = now + msecs;
+    unrefTimer.when = nowMonotonicTimestamp + msecs;
     debug('unrefTimer scheduled');
     return;
   }
 
-  var when = now + msecs;
+  var when = nowMonotonicTimestamp + msecs;
 
   debug('unrefList find where we can insert');
 
   var cur, them;
 
   for (cur = unrefList._idlePrev; cur != unrefList; cur = cur._idlePrev) {
-    them = cur._idleStart + cur._idleTimeout;
+    them = cur._monotonicStartTime + cur._idleTimeout;
 
     if (when < them) {
       debug('unrefList inserting into middle of list');

lib/tls.js

@@ -28,6 +28,8 @@ var stream = require('stream');
 var assert = require('assert').ok;
 var constants = require('constants');
 
+var Timer = process.binding('timer_wrap').Timer;
+
 var DEFAULT_CIPHERS = 'ECDHE-RSA-AES128-SHA256:AES128-GCM-SHA256:' + // TLS 1.2
                       'RC4:HIGH:!MD5:!aNULL:!EDH';                   // TLS 1.0
 
@@ -790,7 +792,7 @@ function onhandshakestart() {
 
   var self = this;
   var ssl = self.ssl;
-  var now = Date.now();
+  var now = Timer.now();
 
   assert(now >= ssl.lastHandshakeTime);
 

src/timer_wrap.cc

@@ -51,6 +51,8 @@ class TimerWrap : public HandleWrap {
     constructor->InstanceTemplate()->SetInternalFieldCount(1);
     constructor->SetClassName(String::NewSymbol("Timer"));
 
+    NODE_SET_METHOD(constructor, "now", Now);
+
     NODE_SET_PROTOTYPE_METHOD(constructor, "close", HandleWrap::Close);
     NODE_SET_PROTOTYPE_METHOD(constructor, "ref", HandleWrap::Ref);
     NODE_SET_PROTOTYPE_METHOD(constructor, "unref", HandleWrap::Unref);
@@ -163,6 +165,13 @@ class TimerWrap : public HandleWrap {
     MakeCallback(wrap->object_, ontimeout_sym, ARRAY_SIZE(argv), argv);
   }
 
+  static Handle<Value> Now(const Arguments& args) {
+    HandleScope scope;
+
+    double now = static_cast<double>(uv_now(uv_default_loop()));
+    return scope.Close(v8::Number::New(now));
+  }
+
   uv_timer_t handle_;
 };
 

test/common.js

@@ -39,6 +39,13 @@ if (process.platform === 'win32') {
 if (!fs.existsSync(exports.opensslCli))
   exports.opensslCli = false;
 
+if (process.platform === 'win32') {
+  exports.faketimeCli = false;
+} else {
+  exports.faketimeCli = path.join(__dirname, "..", "tools", "faketime", "src",
+    "faketime");
+}
+
 var util = require('util');
 for (var i in util) exports[i] = util[i];
 //for (var i in exports) global[i] = exports[i];

test/timers/test-timers-reliability.js

@@ -0,0 +1,53 @@
+// FaketimeFlags: --exclude-monotonic -f '2014-07-21 09:00:00'
+
+var common = require('../common');
+
+var Timer  = process.binding('timer_wrap').Timer;
+var assert = require('assert');
+
+var timerFired    = false;
+var intervalFired = false;
+
+/*
+ * This test case aims at making sure that timing utilities such
+ * as setTimeout and setInterval are not vulnerable to time
+ * drifting or inconsistent time changes (such as ntp time sync
+ * in the past, etc.).
+ *
+ * It is run using faketime so that we change how
+ * non-monotonic clocks perceive time movement. We freeze
+ * non-monotonic time, and check if setTimeout and setInterval
+ * work properly in that situation.
+ *
+ * We check this by setting a timer based on a monotonic clock
+ * to fire after setTimeout's callback is supposed to be called.
+ * This monotonic timer, by definition, is not subject to time drifting
+ * and inconsistent time changes, so it can be considered as a solid
+ * reference.
+ *
+ * When the monotonic timer fires, if the setTimeout's callback
+ * hasn't been called yet, it means that setTimeout's underlying timer
+ * is vulnerable to time drift or inconsistent time changes.
+ */
+
+var monoTimer = new Timer();
+monoTimer.ontimeout = function () {
+    /*
+     * Make sure that setTimeout's and setInterval's callbacks have
+     * already fired, otherwise it means that they are vulnerable to
+     * time drifting or inconsistent time changes.
+     */
+    assert(timerFired);
+    assert(intervalFired);
+};
+
+monoTimer.start(300, 0);
+
+var timer = setTimeout(function () {
+    timerFired = true;
+}, 200);
+
+var interval = setInterval(function () {
+    intervalFired = true;
+    clearInterval(interval);
+}, 200);

test/timers/testcfg.py

@@ -0,0 +1,102 @@
+# Copyright 2008 the V8 project authors. All rights reserved.
+# Redistribution and use in source and binary forms, with or without
+# modification, are permitted provided that the following conditions are
+# met:
+#
+#     * Redistributions of source code must retain the above copyright
+#       notice, this list of conditions and the following disclaimer.
+#     * Redistributions in binary form must reproduce the above
+#       copyright notice, this list of conditions and the following
+#       disclaimer in the documentation and/or other materials provided
+#       with the distribution.
+#     * Neither the name of Google Inc. nor the names of its
+#       contributors may be used to endorse or promote products derived
+#       from this software without specific prior written permission.
+#
+# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+# "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+# LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+# A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+# OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+# SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+# LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+# DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+# THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+# (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+import test
+import os
+import shutil
+from shutil import rmtree
+from os import mkdir
+from glob import glob
+from os.path import join, dirname, exists
+import re
+import shlex
+
+FAKETIME_FLAGS_PATTERN = re.compile(r"//\s+FaketimeFlags:(.*)")
+FAKETIME_BIN_PATH = os.path.join("tools", "faketime", "src", "faketime")
+
+class TimersTestCase(test.TestCase):
+
+  def __init__(self, path, file, mode, context, config):
+    super(TimersTestCase, self).__init__(context, path, mode)
+    self.file = file
+    self.config = config
+    self.mode = mode
+
+  def GetLabel(self):
+    return "%s %s" % (self.mode, self.GetName())
+
+  def GetName(self):
+    return self.path[-1]
+
+  def GetCommand(self):
+    result = [FAKETIME_BIN_PATH];
+
+    source = open(self.file).read()
+    faketime_flags_match = FAKETIME_FLAGS_PATTERN.search(source)
+    if faketime_flags_match:
+      result += shlex.split(faketime_flags_match.group(1).strip())
+
+    result += [self.config.context.GetVm(self.mode)]
+    result += [self.file]
+
+    return result
+
+  def GetSource(self):
+    return open(self.file).read()
+
+
+class TimersTestConfiguration(test.TestConfiguration):
+
+  def __init__(self, context, root):
+    super(TimersTestConfiguration, self).__init__(context, root)
+
+  def Ls(self, path):
+    def SelectTest(name):
+      return name.startswith('test-') and name.endswith('.js')
+    return [f[:-3] for f in os.listdir(path) if SelectTest(f)]
+
+  def ListTests(self, current_path, path, mode):
+    all_tests = [current_path + [t] for t in self.Ls(join(self.root))]
+    result = []
+    for test in all_tests:
+      if self.Contains(path, test):
+        file_path = join(self.root, reduce(join, test[1:], "") + ".js")
+        result.append(TimersTestCase(test, file_path, mode, self.context, self))
+    return result
+
+  def GetBuildRequirements(self):
+    return ['sample', 'sample=shell']
+
+  def GetTestStatus(self, sections, defs):
+    status_file = join(self.root, 'simple.status')
+    if exists(status_file):
+      test.ReadConfigurationInto(status_file, sections, defs)
+
+
+
+def GetConfiguration(context, root):
+  return TimersTestConfiguration(context, root)

tools/Makefile

@@ -0,0 +1,20 @@
+FAKETIME_REPO       := git://github.com/wolfcw/libfaketime.git
+FAKETIME_LOCAL_REPO := $(CURDIR)/faketime
+FAKETIME_BRANCH     := master
+FAKETIME_BINARY     := $(FAKETIME_PREFIX)/bin/faketime
+
+.PHONY: faketime
+
+faketime: $(FAKETIME_BINARY)
+
+clean:
+	$(RM) -r $(FAKETIME_LOCAL_REPO)
+
+$(FAKETIME_BINARY): $(FAKETIME_LOCAL_REPO)
+	cd $(FAKETIME_LOCAL_REPO) && \
+	git checkout $(FAKETIME_BRANCH) && \
+	PREFIX=$(FAKETIME_LOCAL_REPO)/src make
+
+$(FAKETIME_LOCAL_REPO):
+	git clone $(FAKETIME_REPO) $(FAKETIME_LOCAL_REPO)
+