Repository navigation
perf_hooks.PerformanceObserver is very slow #464
Description
Activity
- changed the title
[-]NodeJS perf_hooks.PerformanceObserver is very slow[/-][+]perf_hooks.PerformanceObserver is very slow[/+]on Jan 27, 2021 Also note, when running TypeScript without
--extendedDiagnosticsfor the cases above, the total compile time numbers are fairly stable across each scenario:TypeScript NodeJS Turbo 1 Total Time 2 4.0.5 3 v12.13.0 No 9.416s 4.0.5 v14.15.4 Yes 9.339s 4.0.5 v14.15.4 No 9.336s 4.0.5 v16.0.0-nightly2021012613ac5fbc57 Yes 9.514s 4.0.5 v16.0.0-nightly2021012613ac5fbc57 No 9.456s 4.1.3 4 v12.13.0 No 8.968s 4.1.3 v14.15.4 Yes 8.915s 4.1.3 v14.15.4 No 8.870s 4.1.3 v16.0.0-nightly2021012613ac5fbc57 Yes 9.008s 4.1.3 v16.0.0-nightly2021012613ac5fbc57 No 9.062s - Indicates whether
--turbo-fast-api-callswas passed to NodeJS - Median of 9 runs on an Ubuntu Server machine without
--extendedDiagnostics - typescript@4.0.5 used our custom performance measurement API
- typescript@4.1.3 uses
perf_hooks.performanceandperf_hooks.PerformanceObserver
Another note is that the difference between using and not using
--extendedDiagnosticsin TS 4.0.5 (prior to our switch toPerformanceObserver) was only an increase in about ~150ms to ~400ms, rather than the ~2,000ms increase we've seen withPerformanceObserver.- Indicates whether
Yep, the implementation could definitely use a performance overhaul. I've had it on my list for a while but haven't been able to prioritize it. There are a couple of key challenges on it, the most significant of which is just the cost of creating the
PerformanceEntryinstances and passing those back to the JavaScript side. I can certainly start to look into it but it would be helpful to have a bit more information on which PerformanceEntry types you are observing and what your target benchmarks would be.We use marks for two purposes:
- As a start/end entry for use with
performance.measure. - As a performance counter (i.e., this mark was encountered n times).
We use measures to calculate the total amount of time we spend in various operations, in aggregate. For example,
one of our measurements is I/O Read Time, in which we set a startingmarkbefore we read from the file system, and an endingmarkonce the read has completed. From those two points we add ameasurefor the entire I/O Read operation. For a large project this could be hundreds of files. In the end, we present to the user a list of diagnostics about their compilation. For a measurement like I/O Read Time, this means aggregating the durations of every relatedmeasure.There were a few things we've noticed when running microbenchmarks for
performance.markwhile investigating this:- About 10% of the time is spent computing an isolate-specific marker name
- About 65% of the time is spent in
v8::Object::DefineOwnProperty
@amcasey may be able to provide additional details, as he's been the one investigating the performance impact.
Reacted by Andrew Casey and James M Snell- As a start/end entry for use with
Fantastic. That makes sense. I've already got some ideas on improving things.
Ok, so nodejs/node#37136 has a complete rework of the user timing implementation that improves performance significantly. It is, however, semver-major. Assuming we're able to get it landed in the main repo I'll see if there's a way to backport a subset of the changes in a semver-minor PR.
- added a commit that references this issue
on Feb 22, 2021 This issue is stale because it has been open many days with no activity. It will be closed soon unless the stale label is removed or a comment is made.
I neglected to look into the solution in nodejs/node#37136. Unfortunately, it depends on
setImmediate, which means that while the solution may improve performance, it means thatPerformanceObserveris still completely unusable for us since the TypeScript command line compiler (tsc.js) runs to completion synchronously, so we will never be able to observe the buffered events.Yeah I've been thinking about options there. I prefer deferring the observer by default but I'm thinking about adding an option to force it sync or have it use the microtaskqueue instead.
- added a commit that references this issue
on Jul 25, 2021 - added a commit that references this issue
on Jul 26, 2021 - added a commit that references this issue
on Jul 29, 2021 - added a commit that references this issue
on Aug 16, 2021
Back in October of 2020, TypeScript switched (1, 2) from using our own performance measurement API to using
perf_hooks.performanceandperf_hooks.PerformanceObserver. Since then we have had some users reporting that building with TypeScript using our--diagnosticsor--extendedDiagnosticsflags (which enables on our performance measurement functionality) has caused build time to regress by an additional 20% in some cases prior to this change.We had two goals with our original change:
--cpu-profwith the hopes that we could generate cpu profiles with user timings information.However, we may be forced to revert to our previous custom implementation due to the significant overhead incurred using
PerformanceObserver.Our expectation would be that using performance measurement APIs shouldn't significantly impact the performance of observed code (though we are aware that its impossible for performance measurement to be completely free).
On a side note, I spoke with @devsnek offline and they suggested we try our scenario using a recent NodeJS 15 build and the
--turbo-fast-api-callsflag. The table below reflects the results of running the compiler with and without this flag on different NodeJS versions when compilingant-design/antd:--turbo-fast-api-callswas passed to NodeJS--extendedDiagnosticsperf_hooks.performanceandperf_hooks.PerformanceObserverI'd like to point out several take-aways from the table above:
perf_hooks.PerformanceObserveris generally about 17.5% slower in the above benchmarks than our prior custom measurement API.--turbo-fast-api-callsactually makes things worse rather than better.In the event I'm doing something wrong with our use of
PerformanceObserver, you can find the source for our performance wrapper (which essentially just forwards calls tomarkandmeasureand uses aPerformanceObserverto capture information) here: https://github.com/microsoft/TypeScript/blob/cdd11e96ad3dd039da76c1506e35bc7e74dd57f1/src/compiler/performance.ts