perf_hooks: emit user timing marks, measures and timerify to trace events by jasnell · Pull Request #18789 · nodejs/node · GitHub

Emit user timing marks/measures and performance.timerify() measures to trace events.

/cc @nodejs/diagnostics @mcollina

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
documentation is changed or added
commit message follows commit guidelines

Affected core subsystem(s)

perf_hooks, trace_events

Didn’t review closely but tests are missing.

IIRC, this is doing a floating point divide which is more expensive than an integer divide. 1000 would be an integral constant.

ah yeah, good point :-)

Confirmed. Floating point divide + 2 conversions between integer and floating point.

#include <stdint.h>
uint64_t foo(uint64_t nanos) {
   return nanos / 1e3;
}
// clang -O3 -mllvm --x86-asm-syntax=intel -S foo.c

	movq	xmm0, rdi
	punpckldq	xmm0, xmmword ptr [rip + LCPI0_0] ## xmm0 = xmm0[0],mem[0],xmm0[1],mem[1]
	subpd	xmm0, xmmword ptr [rip + LCPI0_1]
	haddpd	xmm0, xmm0
	divsd	xmm0, qword ptr [rip + LCPI0_2]
	movsd	xmm1, qword ptr [rip + LCPI0_3] ## xmm1 = mem[0],zero
	movapd	xmm2, xmm0
	subsd	xmm2, xmm1
	cvttsd2si	rax, xmm2
	movabs	rcx, -9223372036854775808
	xor	rcx, rax
	cvttsd2si	rax, xmm0
	ucomisd	xmm0, xmm1
	cmovae	rax, rcx
	pop	rbp
	ret

@ofrobots ... nit fixed!
@AndreasMadsen ... test added.

Question: what would the the correct context here? To me it seems that an AsyncResource or async_context be created when the observer is constructed, and that should be used on the callback. Do you agree?

Aside: Do our compilers support async_context{0,0} syntax yet?

Still thinking about that. PerformanceObserver currently is not an AsyncResource and only actually exists on the JS side. Making it an AsyncResource would be a minor divergence from the spec but is certainly not out of the question.

And I don't know about the compilers question.

If you don't want to inherit from AsyncResource, you can attache an async_context to the PerformanceObserver instances for the same effect.

I'm okay if you want to do this in a follow-on, as the issue existed before this PR, and is orthogonal.

Added example to #18810 in case it is useful. If the CI passes there, then that would answer the compiler question :).

@ofrobots ... just went ahead and made PerformanceObserver an AsyncResource.

CI: https://ci.nodejs.org/job/node-test-pull-request/13220/

New CI: https://ci.nodejs.org/job/node-test-pull-request/13230/

CI is looking good with one unrelated failure.

Is a sync with upstream?

In sync with upstream? Nope, not yet. But that reminds me...

@ofrobots ... ^^ To implement this I needed this macro implemented also.

@jasnell created https://chromium-review.googlesource.com/c/v8/v8/+/924507 that adds the same macro upstream.

Note that for the trace-event macros, a sync with upstream is no longer a necessity. Our copy of trace_event.h is derived from upstream, but has a slightly different implementation. It is okay for them to pick up features at a different pace. Please do continue to ping if we add more macros locally. There is no need to block on upstream.

LGTM with a nit

The flag should be named --trace-events-categories for consistency.

This flag already exists and is not introduced by this PR

Adds the `node.perf.usertiming` trace events category for recording usertiming marks and measures (e.g. `perf_hooks.performance.mark()`) in the trace events timeline. Adds the `node.perf.function` trace events category for recording `perf_hooks.performance.timerify()` durations in the trace events timeline.

PR-URL: #18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

Adds the `node.perf.usertiming` trace events category for recording usertiming marks and measures (e.g. `perf_hooks.performance.mark()`) in the trace events timeline. Adds the `node.perf.function` trace events category for recording `perf_hooks.performance.timerify()` durations in the trace events timeline. PR-URL: #18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

PR-URL: #18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

Landed in aca8e76, 9e509b6, and 009e418

Should this be backported to v9.x-staging? If yes please follow the guide and raise a backport PR, if not let me know or add the dont-land-on label.

This depends on #17640 which can't go in v9.x.

PR-URL: nodejs#18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

Adds the `node.perf.usertiming` trace events category for recording usertiming marks and measures (e.g. `perf_hooks.performance.mark()`) in the trace events timeline. Adds the `node.perf.function` trace events category for recording `perf_hooks.performance.timerify()` durations in the trace events timeline. PR-URL: nodejs#18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

PR-URL: nodejs#18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

This reverts commit 009e418. AFAIU the discussion at [1], PerformanceObserver had been made to inherit from AsyncResource more or less as a band-aid in lack of a better async_context candidate to invoke it in. In order to enable access to AsyncLocalStores from PerformanceObservers invoked synchronously through e.g. measure() or mark(), the current async_context, if any, should be retained. Note that this is a breaking change, but - as has been commented at [1], PerformanceObserver being derived from AsyncResource is a "minor divergence from the spec" anyway, - to my knowledge this is an internal implementation detail which has never been documented and - I can't think of a good reason why existing PerformanceObserver implementations would possibly rely on it. OTOH, it's probably worthwhile to not potentially invoke before() and after() async_hooks for each and every PerformanceObserver notification. [1] nodejs#18789 Co-Authored-By: ZauberNerd <zaubernerd@zaubernerd.de> PR-URL: nodejs#36343 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Rich Trott <rtrott@gmail.com>

This reverts commit 009e418. AFAIU the discussion at [1], PerformanceObserver had been made to inherit from AsyncResource more or less as a band-aid in lack of a better async_context candidate to invoke it in. In order to enable access to AsyncLocalStores from PerformanceObservers invoked synchronously through e.g. measure() or mark(), the current async_context, if any, should be retained. Note that this is a breaking change, but - as has been commented at [1], PerformanceObserver being derived from AsyncResource is a "minor divergence from the spec" anyway, - to my knowledge this is an internal implementation detail which has never been documented and - I can't think of a good reason why existing PerformanceObserver implementations would possibly rely on it. OTOH, it's probably worthwhile to not potentially invoke before() and after() async_hooks for each and every PerformanceObserver notification. [1] #18789 Co-Authored-By: ZauberNerd <zaubernerd@zaubernerd.de> PR-URL: #36343 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Rich Trott <rtrott@gmail.com>

jasnell added trace_events Issues and PRs related to V8, Node.js core, and userspace code trace events. perf_hooks Issues and PRs related to the implementation of the Performance Timing API. labels Feb 14, 2018

nodejs-github-bot added the c++ Issues and PRs that require attention from people who are familiar with C++. label Feb 14, 2018

ofrobots reviewed Feb 15, 2018

View reviewed changes

ofrobots reviewed Feb 16, 2018

View reviewed changes

ofrobots approved these changes Feb 16, 2018

View reviewed changes

jasnell force-pushed the perf_trace_event branch from 564a74f to c6ecad5 Compare February 16, 2018 20:13

jasnell force-pushed the perf_trace_event branch from c6ecad5 to 4108481 Compare February 16, 2018 20:23

jasnell force-pushed the perf_trace_event branch from 4108481 to ac17e74 Compare February 17, 2018 00:10

BridgeAR added the author ready PRs that have at least one approval, no outstanding review comments, and a CI started. label Feb 17, 2018

AndreasMadsen reviewed Feb 17, 2018

View reviewed changes

mcollina approved these changes Feb 19, 2018

View reviewed changes

danbev mentioned this pull request Feb 21, 2018

src: fix deprecation warning in node_perf.cc #18877

Closed

2 tasks

perf_hooks: eliminate deprecation warning

47a1898

jasnell force-pushed the perf_trace_event branch from ac17e74 to f67e78d Compare February 26, 2018 19:28

jasnell added 2 commits February 26, 2018 11:29

perf_hooks: make PerformanceObserver an AsyncResource

02adcf7

jasnell force-pushed the perf_trace_event branch from f67e78d to 02adcf7 Compare February 26, 2018 19:29

jasnell added the semver-minor PRs that contain new features and should be released in the next minor version. label Feb 26, 2018

jasnell added a commit that referenced this pull request Feb 26, 2018

perf_hooks: eliminate deprecation warning

aca8e76

PR-URL: #18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

jasnell added a commit that referenced this pull request Feb 26, 2018

perf_hooks: make PerformanceObserver an AsyncResource

009e418

PR-URL: #18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

jasnell closed this Feb 26, 2018

MylesBorins added the backport-requested-v9.x label Mar 6, 2018

targos added dont-land-on-v9.x and removed author ready PRs that have at least one approval, no outstanding review comments, and a CI started. backport-requested-v9.x labels Apr 2, 2018

MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018

perf_hooks: eliminate deprecation warning

d09dc7d

PR-URL: nodejs#18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

MayaLekova pushed a commit to MayaLekova/node that referenced this pull request May 8, 2018

perf_hooks: make PerformanceObserver an AsyncResource

94114e7

PR-URL: nodejs#18789 Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com> Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

MylesBorins added the dont-land-on-v8.x label Aug 7, 2018

perf_hooks: emit user timing marks, measures and timerify to trace events by jasnell · Pull Request #18789 · nodejs/node · GitHub

Uh oh!

Uh oh!

perf_hooks: emit user timing marks, measures and timerify to trace events - #18789

perf_hooks: emit user timing marks, measures and timerify to trace events#18789jasnell wants to merge 3 commits intonodejs:masternodejs/node:masterfrom jasnell:perf_trace_eventjasnell/node:perf_trace_eventCopy head branch name to clipboard

Conversation

jasnell commented Feb 14, 2018

Checklist

Affected core subsystem(s)

Uh oh!

AndreasMadsen commented Feb 15, 2018

Uh oh!

ofrobots Feb 15, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jasnell commented Feb 15, 2018

Uh oh!

ofrobots Feb 16, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jasnell commented Feb 16, 2018

Uh oh!

jasnell commented Feb 16, 2018

Uh oh!

jasnell commented Feb 17, 2018

Uh oh!

jasnell commented Feb 17, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mcollina left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jasnell commented Feb 26, 2018

Uh oh!

MylesBorins commented Mar 6, 2018

Uh oh!

targos commented Apr 2, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

8 participants

perf_hooks: emit user timing marks, measures and timerify to trace events#18789
jasnell wants to merge 3 commits into
nodejs:masterfrom
jasnell:perf_trace_event

ofrobots Feb 15, 2018 •
edited
Loading

ofrobots Feb 16, 2018 •
edited
Loading