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.

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

Use uv_hrtime as tracing timestamp #18196

Merged
merged 3 commits into from
Jan 24, 2018

Conversation

ofrobots
Copy link
Contributor

@ofrobots ofrobots commented Jan 17, 2018

Use uv_hrtime as the time source for tracing. The PR also includes two API changing cherry-picks from upstream that allow us to override the time source.

Fixes: #17349

/cc @AndreasMadsen @jasnell @nodejs/v8

Checklist
  • make -j4 test (UNIX), or vcbuild test (Windows) passes
  • commit message follows commit guidelines
Affected core subsystem(s)

tracing

CI: https://ci.nodejs.org/job/node-test-pull-request/12574/ https://ci.nodejs.org/job/node-test-pull-request/12662/
V8-CI: https://ci.nodejs.org/view/All/job/node-test-commit-v8-linux/1164/

@nodejs-github-bot nodejs-github-bot added the lib / src Issues and PRs related to general changes in the lib or src directory. label Jan 17, 2018
@ofrobots ofrobots added the semver-major PRs that contain breaking changes and should be released in the next major version. label Jan 17, 2018
@AndreasMadsen
Copy link
Member

@ofrobots Why is this a semver major?

Copy link
Member

@bnoordhuis bnoordhuis left a comment

Choose a reason for hiding this comment

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

LGTM at a quick glance.

@AndreasMadsen ABI change. The added virtual methods change TracingController's vtable.

(Could be avoided if CurrentTimestampMicroseconds() was a function pointer and CurrentCpuTimestampMicroseconds() and removed/hidden/inlined.)

@AndreasMadsen
Copy link
Member

@bnoordhuis Ah, I see.

@ofrobots You should properly document that the clock is process.hrtime() in https://github.com/nodejs/node/blob/master/doc/api/tracing.md

I think that documentation needs a huge rewrite, but it should still be included.

@ofrobots
Copy link
Contributor Author

@AndreasMadsen documented the time source in tracing.md. PTAL.

Copy link
Member

@AndreasMadsen AndreasMadsen left a comment

Choose a reason for hiding this comment

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

LGTM

TracingController() : v8::platform::tracing::TracingController() {}

int64_t CurrentTimestampMicroseconds() override {
return uv_hrtime();
Copy link
Member

Choose a reason for hiding this comment

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

is it OK to return nanoseconds instead of microseconds?

Copy link
Member

Choose a reason for hiding this comment

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

Pretty sure it is okay. But properly we should use microseconds, such that it is less of a breaking change.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@targos thanks for catching this! I had a division in my original test commit but I ended up losing while manually porting the change. D'oh.

@AndreasMadsen The trace-event framework requires the timestamp to be in micro-seconds, and all the current tooling available in chrome or through the catapult project would not work correctly if this was in nano-seconds.

@@ -19,3 +19,6 @@ node --trace-events-enabled --trace-event-categories v8,node,node.async_hooks se
Running Node.js with tracing enabled will produce log files that can be opened
in the [`chrome://tracing`](https://www.chromium.org/developers/how-tos/trace-event-profiling-tool)
tab of Chrome.

Starting with Node v10.0.0, the tracing system uses the same time source as the
Copy link
Member

Choose a reason for hiding this comment

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

nit, s/Node v10.0.0/Node.js 10.0.0

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Done.


Starting with Node 10.0.0, the tracing system uses the same time source as the
one used by `process.hrtime()` however the trace-event timestamps are expressed
in micro-seconds, unlike `process.hrtime()` which returns nano-seconds.
Copy link
Member

Choose a reason for hiding this comment

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

"Microseconds" and "nanoseconds" don't have dashes in them.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thanks. Done.

Original commit message:

    [tracing] allow embedders to provide own tracing timestamps

    Make it possible for embedders to provide their own tracing timetamps by
    providing an overridable virtual function on V8's tracing controller.

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: I727e633cb7f63d4b41c2e427ecca3c9174c90bfe
    Reviewed-on: https://chromium-review.googlesource.com/847690
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50489}

Refs: v8/v8@814577e
Refs: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
Original commit message:

    [tracing] implement TRACE_EVENT_ADD_WITH_TIMESTAMP

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: Icb3cf7b7f96704e1eaa4c5fbf773b94b70cddc85
    Reviewed-on: https://chromium-review.googlesource.com/861302
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50549}

Refs: v8/v8@c3bb73f
Refs: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
Override the V8 TracingController to provide uv_hrtime based
timestamps. This allows tracing timestamps to be comparable with
process.hrtime timestamps.

Fixes: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
@ofrobots ofrobots merged commit 98d9540 into nodejs:master Jan 24, 2018
@ofrobots
Copy link
Contributor Author

ofrobots commented Jan 24, 2018

CI failures looked like flakes/infra-issues. V8-CI was clean.

Landed as 2313424...98d9540.

@ofrobots ofrobots deleted the backport-with-timestamp branch January 24, 2018 18:16
@apapirovski apapirovski mentioned this pull request Jan 24, 2018
6 tasks
ofrobots added a commit to ofrobots/node that referenced this pull request Jan 24, 2018
Original commit message:

    [tracing] allow embedders to provide own tracing timestamps

    Make it possible for embedders to provide their own tracing timetamps by
    providing an overridable virtual function on V8's tracing controller.

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: I727e633cb7f63d4b41c2e427ecca3c9174c90bfe
    Reviewed-on: https://chromium-review.googlesource.com/847690
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50489}

Refs: v8/v8@814577e
Refs: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
ofrobots added a commit to ofrobots/node that referenced this pull request Jan 24, 2018
Original commit message:

    [tracing] implement TRACE_EVENT_ADD_WITH_TIMESTAMP

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: Icb3cf7b7f96704e1eaa4c5fbf773b94b70cddc85
    Reviewed-on: https://chromium-review.googlesource.com/861302
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50549}

Refs: v8/v8@c3bb73f
Refs: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
ofrobots added a commit that referenced this pull request Jan 25, 2018
Original commit message:

    [tracing] allow embedders to provide own tracing timestamps

    Make it possible for embedders to provide their own tracing timetamps by
    providing an overridable virtual function on V8's tracing controller.

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: I727e633cb7f63d4b41c2e427ecca3c9174c90bfe
    Reviewed-on: https://chromium-review.googlesource.com/847690
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{#50489}

Refs: v8/v8@814577e
Refs: #17349
PR-URL: #18196
Refs: #18360
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
ofrobots added a commit that referenced this pull request Jan 25, 2018
Original commit message:

    [tracing] implement TRACE_EVENT_ADD_WITH_TIMESTAMP

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: Icb3cf7b7f96704e1eaa4c5fbf773b94b70cddc85
    Reviewed-on: https://chromium-review.googlesource.com/861302
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{#50549}

Refs: v8/v8@c3bb73f
Refs: #17349
PR-URL: #18196
Refs: #18360
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018
Original commit message:

    [tracing] allow embedders to provide own tracing timestamps

    Make it possible for embedders to provide their own tracing timetamps by
    providing an overridable virtual function on V8's tracing controller.

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: I727e633cb7f63d4b41c2e427ecca3c9174c90bfe
    Reviewed-on: https://chromium-review.googlesource.com/847690
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50489}

Refs: v8/v8@814577e
Refs: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018
Original commit message:

    [tracing] implement TRACE_EVENT_ADD_WITH_TIMESTAMP

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: Icb3cf7b7f96704e1eaa4c5fbf773b94b70cddc85
    Reviewed-on: https://chromium-review.googlesource.com/861302
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50549}

Refs: v8/v8@c3bb73f
Refs: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018
Override the V8 TracingController to provide uv_hrtime based
timestamps. This allows tracing timestamps to be comparable with
process.hrtime timestamps.

Fixes: nodejs#17349
PR-URL: nodejs#18196
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018
Original commit message:

    [tracing] allow embedders to provide own tracing timestamps

    Make it possible for embedders to provide their own tracing timetamps by
    providing an overridable virtual function on V8's tracing controller.

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: I727e633cb7f63d4b41c2e427ecca3c9174c90bfe
    Reviewed-on: https://chromium-review.googlesource.com/847690
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50489}

Refs: v8/v8@814577e
Refs: nodejs#17349
PR-URL: nodejs#18196
Refs: nodejs#18360
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018
Original commit message:

    [tracing] implement TRACE_EVENT_ADD_WITH_TIMESTAMP

    Bug:
    Cq-Include-Trybots: master.tryserver.chromium.linux:linux_chromium_rel_ng
    Change-Id: Icb3cf7b7f96704e1eaa4c5fbf773b94b70cddc85
    Reviewed-on: https://chromium-review.googlesource.com/861302
    Reviewed-by: Fadi Meawad <fmeawad@chromium.org>
    Reviewed-by: Yang Guo <yangguo@chromium.org>
    Commit-Queue: Ali Ijaz Sheikh <ofrobots@google.com>
    Cr-Commit-Position: refs/heads/master@{nodejs#50549}

Refs: v8/v8@c3bb73f
Refs: nodejs#17349
PR-URL: nodejs#18196
Refs: nodejs#18360
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Andreas Madsen <amwebdk@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
lib / src Issues and PRs related to general changes in the lib or src directory. semver-major PRs that contain breaking changes and should be released in the next major version.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants