Use uv_hrtime as tracing timestamp #18196

ofrobots · 2018-01-17T01:21:54Z

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/

AndreasMadsen · 2018-01-17T09:18:52Z

@ofrobots Why is this a semver major?

bnoordhuis

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 · 2018-01-17T10:33:23Z

@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 · 2018-01-20T06:12:38Z

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

AndreasMadsen

LGTM

targos · 2018-01-20T08:43:28Z

src/tracing/agent.h

+  TracingController() : v8::platform::tracing::TracingController() {}
+
+  int64_t CurrentTimestampMicroseconds() override {
+    return uv_hrtime();


is it OK to return nanoseconds instead of microseconds?

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

@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.

jasnell · 2018-01-22T15:51:57Z

doc/api/tracing.md

@@ -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


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

bnoordhuis · 2018-01-22T21:55:16Z

doc/api/tracing.md

+
+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.


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

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 · 2018-01-24T18:16:23Z

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

Landed as 2313424...98d9540.

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>

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>

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>

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>

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>

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>

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 added the semver-major PRs that contain breaking changes and should be released in the next major version. label Jan 17, 2018

ofrobots force-pushed the backport-with-timestamp branch from b51f778 to 80f4175 Compare January 17, 2018 01:29

bnoordhuis approved these changes Jan 17, 2018

View reviewed changes

jasnell approved these changes Jan 17, 2018

View reviewed changes

addaleax approved these changes Jan 17, 2018

View reviewed changes

AndreasMadsen approved these changes Jan 20, 2018

View reviewed changes

targos reviewed Jan 20, 2018

View reviewed changes

jasnell reviewed Jan 22, 2018

View reviewed changes

bnoordhuis approved these changes Jan 22, 2018

View reviewed changes

ofrobots added 3 commits January 24, 2018 09:58

ofrobots force-pushed the backport-with-timestamp branch from 53e7963 to 98d9540 Compare January 24, 2018 18:00

ofrobots merged commit 98d9540 into nodejs:master Jan 24, 2018

ofrobots deleted the backport-with-timestamp branch January 24, 2018 18:16

apapirovski mentioned this pull request Jan 24, 2018

deps: update V8 to 6.4 #17489

Closed

6 tasks

ofrobots mentioned this pull request Jan 24, 2018

Refloat cherry-picks from #18196 #18360

Closed

kfarnung mentioned this pull request Jan 25, 2018

Build break in src/tracing/agent.h #18361

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Use uv_hrtime as tracing timestamp #18196

Use uv_hrtime as tracing timestamp #18196

ofrobots commented Jan 17, 2018 •

edited

Loading

AndreasMadsen commented Jan 17, 2018

bnoordhuis left a comment

AndreasMadsen commented Jan 17, 2018

ofrobots commented Jan 20, 2018

AndreasMadsen left a comment

targos Jan 20, 2018

AndreasMadsen Jan 20, 2018

ofrobots Jan 22, 2018

jasnell Jan 22, 2018

ofrobots Jan 22, 2018

bnoordhuis Jan 22, 2018

ofrobots Jan 22, 2018

ofrobots commented Jan 24, 2018 •

edited

Loading

Use uv_hrtime as tracing timestamp #18196

Use uv_hrtime as tracing timestamp #18196

Conversation

ofrobots commented Jan 17, 2018 • edited Loading

Checklist

Affected core subsystem(s)

AndreasMadsen commented Jan 17, 2018

bnoordhuis left a comment

Choose a reason for hiding this comment

AndreasMadsen commented Jan 17, 2018

ofrobots commented Jan 20, 2018

AndreasMadsen left a comment

Choose a reason for hiding this comment

targos Jan 20, 2018

Choose a reason for hiding this comment

AndreasMadsen Jan 20, 2018

Choose a reason for hiding this comment

ofrobots Jan 22, 2018

Choose a reason for hiding this comment

jasnell Jan 22, 2018

Choose a reason for hiding this comment

ofrobots Jan 22, 2018

Choose a reason for hiding this comment

bnoordhuis Jan 22, 2018

Choose a reason for hiding this comment

ofrobots Jan 22, 2018

Choose a reason for hiding this comment

ofrobots commented Jan 24, 2018 • edited Loading

ofrobots commented Jan 17, 2018 •

edited

Loading

ofrobots commented Jan 24, 2018 •

edited

Loading