Skip to content

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

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

Merged
targos merged 3 commits into from
Oct 16, 2015
+21 −20
Merged

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

Show file tree
Hide file tree
Changes from 1 commit
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
Next Next commit
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 <rtrott@gmail.com>
Reviewed-By: Roman Reiss <me@silverwind.io>
Reviewed-By: Trevor Norris <trev.norris@gmail.com>
  • Loading branch information
@targos
targos committed Oct 16, 2015
commit 419f7d472687ba65715b593a2660f12b84ed0ec8
2 changes: 1 addition & 1 deletion doc/api/console.markdown
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ Example:
;
}
console.timeEnd('100-elements');
// prints 100-elements: 262ms
// prints 100-elements: 225.438ms
Copy link
Copy Markdown
Contributor

@thefourtheye thefourtheye Oct 3, 2015

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
Copy Markdown
Member

@ChALkeR ChALkeR Oct 7, 2015

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
Copy Markdown
Member Author

@targos targos Oct 8, 2015

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
7 changes: 4 additions & 3 deletions lib/console.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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());
};


Expand All @@ -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));
};


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
Copy Markdown
Contributor

@aheckmann aheckmann Oct 5, 2015

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
Copy Markdown
Member Author

@targos targos Oct 5, 2015

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
Copy Markdown
Member

@jasnell jasnell Oct 6, 2015

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
Copy Markdown
Member

@ChALkeR ChALkeR Oct 7, 2015

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);