From 419f7d472687ba65715b593a2660f12b84ed0ec8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C3=ABl=20Zasso?= Date: Wed, 7 Oct 2015 19:58:39 +0200 Subject: [PATCH 1/3] console: sub-millisecond accuracy for console.time This makes the output of console.timeEnd in line with major browsers. PR-URL: https://github.com/nodejs/node/pull/3166 Reviewed-By: Rich Trott Reviewed-By: Roman Reiss Reviewed-By: Trevor Norris --- doc/api/console.markdown | 2 +- lib/console.js | 7 ++++--- test/parallel/test-console.js | 8 ++++---- 3 files changed, 9 insertions(+), 8 deletions(-) diff --git a/doc/api/console.markdown b/doc/api/console.markdown index 4b5ed61b199e09..329b57ef9b57e6 100644 --- a/doc/api/console.markdown +++ b/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[, ...]) diff --git a/lib/console.js b/lib/console.js index f9032e24a0fa44..531a383876ce2b 100644 --- a/lib/console.js +++ b/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)); }; diff --git a/test/parallel/test-console.js b/test/parallel/test-console.js index 982c83851f072a..f8a927398034cb 100644 --- a/test/parallel/test-console.js +++ b/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); From fc72a578e6ecbc31ae305b479ab8c5824b949482 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C3=ABl=20Zasso?= Date: Wed, 7 Oct 2015 20:01:36 +0200 Subject: [PATCH 2/3] doc: reword description of console.time PR-URL: https://github.com/nodejs/node/pull/3166 Reviewed-By: Rich Trott Reviewed-By: Roman Reiss Reviewed-By: Trevor Norris --- doc/api/console.markdown | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/doc/api/console.markdown b/doc/api/console.markdown index 329b57ef9b57e6..f3a69ce95104e2 100644 --- a/doc/api/console.markdown +++ b/doc/api/console.markdown @@ -74,16 +74,16 @@ Defaults to `false`. Colors are customizable, see below. ### console.time(label) -Used to calculate the duration of a specific operation. To start a timer, call -the `console.time()` method, giving it a name as only parameter. To stop the -timer, and to get the elapsed time in milliseconds, just call the -[`console.timeEnd()`](#console_console_timeend_label) method, again passing the -timer's name as the parameter. +Starts a timer that can be used to compute the duration of an operation. Timers +are identified by a unique name. Use the same name when you call +[`console.timeEnd()`](#console_console_timeend_label) to stop the timer and +output the elapsed time in milliseconds. Timer durations are accurate to the +sub-millisecond. ### console.timeEnd(label) Stops a timer that was previously started by calling -[`console.time()`](#console_console_time_label) and print the result to the +[`console.time()`](#console_console_time_label) and prints the result to the console. Example: From 8c043c12456d9b5a500f9cefcca27a61a1a381cf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C3=ABl=20Zasso?= Date: Thu, 8 Oct 2015 21:19:34 +0200 Subject: [PATCH 3/3] console: rename argument of time and timeEnd Name it timerName instead of label. It is clearer that way and matches the description in the doc. It is also how it's named in MDN. PR-URL: https://github.com/nodejs/node/pull/3166 Reviewed-By: Rich Trott Reviewed-By: Roman Reiss Reviewed-By: Trevor Norris --- doc/api/console.markdown | 8 ++++---- lib/console.js | 12 ++++++------ 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/doc/api/console.markdown b/doc/api/console.markdown index f3a69ce95104e2..6e2de6071e64a2 100644 --- a/doc/api/console.markdown +++ b/doc/api/console.markdown @@ -72,18 +72,18 @@ object. This is useful for inspecting large complicated objects. Defaults to - `colors` - if `true`, then the output will be styled with ANSI color codes. Defaults to `false`. Colors are customizable, see below. -### console.time(label) +### console.time(timerName) Starts a timer that can be used to compute the duration of an operation. Timers are identified by a unique name. Use the same name when you call -[`console.timeEnd()`](#console_console_timeend_label) to stop the timer and +[`console.timeEnd()`](#console_console_timeend_timername) to stop the timer and output the elapsed time in milliseconds. Timer durations are accurate to the sub-millisecond. -### console.timeEnd(label) +### console.timeEnd(timerName) Stops a timer that was previously started by calling -[`console.time()`](#console_console_time_label) and prints the result to the +[`console.time()`](#console_console_time_timername) and prints the result to the console. Example: diff --git a/lib/console.js b/lib/console.js index 531a383876ce2b..d2b4f3fc5b59be 100644 --- a/lib/console.js +++ b/lib/console.js @@ -55,19 +55,19 @@ Console.prototype.dir = function(object, options) { }; -Console.prototype.time = function(label) { - this._times.set(label, process.hrtime()); +Console.prototype.time = function(timerName) { + this._times.set(timerName, process.hrtime()); }; -Console.prototype.timeEnd = function(label) { - var time = this._times.get(label); +Console.prototype.timeEnd = function(timerName) { + var time = this._times.get(timerName); if (!time) { - throw new Error('No such label: ' + label); + throw new Error('No such timer name: ' + timerName); } const duration = process.hrtime(time); const ms = duration[0] * 1000 + duration[1] / 1e6; - this.log('%s: %sms', label, ms.toFixed(3)); + this.log('%s: %sms', timerName, ms.toFixed(3)); };