Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

console: sub-millisecond accuracy for console.time #3166

Merged
merged 3 commits into from
Oct 16, 2015
Merged

console: sub-millisecond accuracy for console.time #3166

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
419f7d4
console: sub-millisecond accuracy for console.time
targos Oct 7, 2015
fc72a57
doc: reword description of console.time
targos Oct 7, 2015
8c043c1
console: rename argument of time and timeEnd
targos Oct 8, 2015
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 9 additions & 9 deletions doc/api/console.markdown
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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)

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_timername) to stop the timer and
output the elapsed time in milliseconds. Timer durations are accurate to the
sub-millisecond.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nittiest of all possible nits: The last sentence describes the timer precision, not the accuracy.

Slightly less nitty nit: sub-millisecond is true, but we know that it will be three decimal places, so you could just say it's to the microsecond.

Of course, I can't come up with wording for either of these nits that's better than what's already there, so ¯_(ツ)_/¯

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The last sentence describes the timer precision, not the accuracy.

You are right, I will replace "accurate" with "precise" when I land it if nobody objects.

... so you could just say it's to the microsecond

I wanted to do that but I am not sure it's true all the time and on all platforms. Perhaps if the CPU is overloaded we can lose precision ? I really don't know.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Another possibility is just to remove that last sentence entirely. I don't think MDN indicates how many decimal places their timer is good for, for example. People can use it and they get as many decimal places as they get.

MDN stuff for reference:

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For this sentence I took inspiration from https://developer.chrome.com/devtools/docs/console-api#consoletimelabel
I fine with removing it as well

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah. Well, in that case, I'm fine with leaving it. If it's good enough for Chrome docs, it's good enough for me.

Sorry for all the bikeshedding on this. LGTM no matter which way you decide to go with it (leave it, remove it, change it as described).


### console.timeEnd(label)
### console.timeEnd(timerName)

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_timername) and prints the result to the
console.

Example:
Expand All @@ -93,7 +93,7 @@ Example:
;
}
console.timeEnd('100-elements');
// prints 100-elements: 262ms
// prints 100-elements: 225.438ms
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why this change is necessary?

Edit: Ah, I see it now. That is kind of the point of this PR

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bikeshedding: this belongs to the first commit «console: sub-millisecond accuracy for console.time», not to «doc: reword description of console.time».

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I moved this change to the first commit


### console.trace(message[, ...])

Expand Down
15 changes: 8 additions & 7 deletions lib/console.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,18 +55,19 @@ Console.prototype.dir = function(object, options) {
};


Console.prototype.time = function(label) {
this._times.set(label, Date.now());
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);
}
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', timerName, ms.toFixed(3));
};


Expand Down
8 changes: 4 additions & 4 deletions test/parallel/test-console.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we consider the output of the console functions to be part of the API, the I think one could view this as semver-major. The change to thses tests demonstrates how downstream apps output parsing will break.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point, I don't know what is the policy about console output.
Recent changes to the output of util.format were considered semver-minor IIRC.
cc @nodejs/collaborators

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm going to say semver-minor for changes to console output but it's never as clear cut as it appears. For this, I personally feel it's small enough of a change that -minor is appropriate.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The probability of this breaking anything is near zero. Still, there seems to be no reason for pulling this into 4.x branch.

assert.equal(strings.length, 0);