console: sub-millisecond accuracy for console.time

This makes the output of console.timeEnd in line with major browsers.

PR-URL: #3166
Reviewed-By: Rich Trott <[email protected]>
Reviewed-By: Roman Reiss <[email protected]>
Reviewed-By: Trevor Norris <[email protected]>

Author: targos

doc/api/console.markdown

@@ -93,7 +93,7 @@ Example:
       ;
     }
     console.timeEnd('100-elements');
-    // prints 100-elements: 262ms
+    // prints 100-elements: 225.438ms
 
 ### console.trace(message[, ...])
 

lib/console.js

@@ -56,7 +56,7 @@ Console.prototype.dir = function(object, options) {
 
 
 Console.prototype.time = function(label) {
-  this._times.set(label, Date.now());
+  this._times.set(label, process.hrtime());
 };
 
 
@@ -65,8 +65,9 @@ Console.prototype.timeEnd = function(label) {
   if (!time) {
     throw new Error('No such label: ' + label);
   }
-  var duration = Date.now() - time;
-  this.log('%s: %dms', label, duration);
+  const duration = process.hrtime(time);
+  const ms = duration[0] * 1000 + duration[1] / 1e6;
+  this.log('%s: %sms', label, ms.toFixed(3));
 };
 
 

test/parallel/test-console.js

@@ -68,8 +68,8 @@ assert.notEqual(-1, strings.shift().indexOf('foo: [Object]'));
 assert.equal(-1, strings.shift().indexOf('baz'));
 assert.equal('Trace: This is a {"formatted":"trace"} 10 foo',
              strings.shift().split('\n').shift());
-assert.ok(/^label: \d+ms$/.test(strings.shift().trim()));
-assert.ok(/^__proto__: \d+ms$/.test(strings.shift().trim()));
-assert.ok(/^constructor: \d+ms$/.test(strings.shift().trim()));
-assert.ok(/^hasOwnProperty: \d+ms$/.test(strings.shift().trim()));
+assert.ok(/^label: \d+\.\d{3}ms$/.test(strings.shift().trim()));
+assert.ok(/^__proto__: \d+\.\d{3}ms$/.test(strings.shift().trim()));
+assert.ok(/^constructor: \d+\.\d{3}ms$/.test(strings.shift().trim()));
+assert.ok(/^hasOwnProperty: \d+\.\d{3}ms$/.test(strings.shift().trim()));
 assert.equal(strings.length, 0);