From 1c02cdd8c572455c73f8c01916b97d0d94f3e66e Mon Sep 17 00:00:00 2001 From: Ruslan Shestopalyuk Date: Tue, 14 Nov 2023 11:21:21 -0800 Subject: [PATCH] Implement "paint time" support in Event Timing API Summary: ## Changelog: [Internal] - Uses mount hooks to report "paint time" via the Event Timing API - i.e. "duration" now corresponds not the the JS dispatch end point, but to the moment when the corresponding mount ("paint") happened on the native side. This feature is disabled by default for now, but can be enabled via `NativePerformanceObserver.setIsReportingEventPaintTime(true);`. Differential Revision: D51313902 --- .../NativePerformanceObserver.cpp | 41 ++++++++++-- .../NativePerformanceObserver.h | 6 ++ .../NativePerformanceObserver.js | 2 + .../PerformanceEntryReporter.cpp | 63 +++++++++++++++++-- .../WebPerformance/PerformanceEntryReporter.h | 23 ++++++- .../__mocks__/NativePerformanceObserver.js | 7 +++ .../react/renderer/core/EventLogger.h | 2 +- .../renderer/core/EventQueueProcessor.cpp | 2 +- 8 files changed, 132 insertions(+), 14 deletions(-) diff --git a/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.cpp b/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.cpp index 206da95d6c269e..02c85250b51d85 100644 --- a/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.cpp +++ b/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.cpp @@ -10,8 +10,12 @@ #include "NativePerformanceObserver.h" #include "PerformanceEntryReporter.h" +#include + #include "Plugins.h" +#include + std::shared_ptr NativePerformanceObserverModuleProvider( std::shared_ptr jsInvoker) { @@ -34,15 +38,44 @@ NativePerformanceObserver::~NativePerformanceObserver() { void NativePerformanceObserver::startReporting( jsi::Runtime& rt, int32_t entryType) { - PerformanceEntryReporter::getInstance().startReporting( - static_cast(entryType)); + PerformanceEntryReporter& reporter = PerformanceEntryReporter::getInstance(); + + PerformanceEntryType entryTypeEnum = + static_cast(entryType); + reporter.startReporting(entryTypeEnum); + + if (entryTypeEnum == PerformanceEntryType::EVENT && + reporter.isReportingEventPaintTime()) { + UIManagerBinding::getBinding(rt)->getUIManager().registerMountHook( + reporter); + } } void NativePerformanceObserver::stopReporting( jsi::Runtime& rt, int32_t entryType) { - PerformanceEntryReporter::getInstance().stopReporting( - static_cast(entryType)); + PerformanceEntryReporter& reporter = PerformanceEntryReporter::getInstance(); + + PerformanceEntryType entryTypeEnum = + static_cast(entryType); + reporter.stopReporting(entryTypeEnum); + + if (entryTypeEnum == PerformanceEntryType::EVENT && + reporter.isReportingEventPaintTime()) { + UIManagerBinding::getBinding(rt)->getUIManager().unregisterMountHook( + reporter); + } +} + +void NativePerformanceObserver::setIsReportingEventPaintTime( + jsi::Runtime& rt, + bool isReportingEventPaintTime) { + PerformanceEntryReporter::getInstance().setIsReportingEventPaintTime( + isReportingEventPaintTime); +} + +bool NativePerformanceObserver::isReportingEventPaintTime(jsi::Runtime& rt) { + return PerformanceEntryReporter::getInstance().isReportingEventPaintTime(); } void NativePerformanceObserver::setIsBuffered( diff --git a/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.h b/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.h index bc55f2476d2132..f67cea7fb198fb 100644 --- a/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.h +++ b/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.h @@ -76,6 +76,12 @@ class NativePerformanceObserver jsi::Runtime& rt, std::optional> callback); + void setIsReportingEventPaintTime( + jsi::Runtime& rt, + bool isReportingEventPaintTime); + + bool isReportingEventPaintTime(jsi::Runtime& rt); + void logRawEntry(jsi::Runtime& rt, RawPerformanceEntry entry); std::vector> getEventCounts( diff --git a/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.js b/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.js index 6db3be05a911a9..057f6b89613219 100644 --- a/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.js +++ b/packages/react-native/Libraries/WebPerformance/NativePerformanceObserver.js @@ -54,6 +54,8 @@ export interface Spec extends TurboModule { entryName?: string, ) => $ReadOnlyArray; +getSupportedPerformanceEntryTypes: () => $ReadOnlyArray; + +isReportingEventPaintTime: () => boolean; + +setIsReportingEventPaintTime: (isReportingEventPaintTime: boolean) => void; } export default (TurboModuleRegistry.get( diff --git a/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.cpp b/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.cpp index ff7389eeb1775a..d74fb38a8588dd 100644 --- a/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.cpp +++ b/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.cpp @@ -8,11 +8,14 @@ #include "PerformanceEntryReporter.h" #include #include +#include #include "NativePerformanceObserver.h" #include #include +#include + namespace facebook::react { EventTag PerformanceEntryReporter::sCurrentEventTag_{0}; @@ -32,6 +35,18 @@ void PerformanceEntryReporter::setReportingCallback( callback_ = callback; } +void PerformanceEntryReporter::setIsReportingEventPaintTime( + bool isReportingEventPaintTime) { + isReportingEventPaintTime_ = isReportingEventPaintTime; + + if (!CoreFeatures::enableMountHooks) { + // Force to false, as this relies on mount hooks being enabled + LOG(WARNING) + << "PerformanceEntryReporter: mount hooks must be enabled to report paint times."; + isReportingEventPaintTime_ = false; + } +} + double PerformanceEntryReporter::getCurrentTimeStamp() const { return timeStampProvider_ != nullptr ? timeStampProvider_() : JSExecutor::performanceNow(); @@ -397,12 +412,12 @@ void PerformanceEntryReporter::onEventDispatch(EventTag tag) { std::scoped_lock lock(eventsInFlightMutex_); auto it = eventsInFlight_.find(tag); if (it != eventsInFlight_.end()) { - it->second.dispatchTime = timeStamp; + it->second.processingStartTime = timeStamp; } } } -void PerformanceEntryReporter::onEventEnd(EventTag tag) { +void PerformanceEntryReporter::onEventDispatchEnd(EventTag tag) { if (!isReporting(PerformanceEntryType::EVENT) || tag == 0) { return; } @@ -414,7 +429,15 @@ void PerformanceEntryReporter::onEventEnd(EventTag tag) { return; } auto& entry = it->second; - auto& name = entry.name; + entry.processingEndTime = timeStamp; + + if (isReportingEventPaintTime_) { + // If reporting paint time, don't send the entry just yet and wait for the + // mount hook callback to be called + return; + } + + const auto& name = entry.name; // TODO: Define the way to assign interaction IDs to the event chains // (T141358175) @@ -423,11 +446,41 @@ void PerformanceEntryReporter::onEventEnd(EventTag tag) { std::string(name), entry.startTime, timeStamp - entry.startTime, - entry.dispatchTime, - timeStamp, + entry.processingStartTime, + entry.processingEndTime, interactionId); eventsInFlight_.erase(it); } } +void PerformanceEntryReporter::shadowTreeDidMount( + const RootShadowNode::Shared& rootShadowNode, + double mountTime) noexcept { + if (!isReporting(PerformanceEntryType::EVENT) || + !isReportingEventPaintTime_) { + return; + } + + std::scoped_lock lock(eventsInFlightMutex_); + auto it = eventsInFlight_.begin(); + while (it != eventsInFlight_.end()) { + const auto& entry = it->second; + if (entry.processingEndTime == 0.0 || entry.processingEndTime > mountTime) { + // This mount doesn't correspond to the event + ++it; + continue; + } + + const uint32_t interactionId = 0; + event( + std::string(entry.name), + entry.startTime, + mountTime - entry.startTime, + entry.processingStartTime, + entry.processingEndTime, + interactionId); + it = eventsInFlight_.erase(it); + } +} + } // namespace facebook::react diff --git a/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.h b/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.h index 5c805beac2d4ca..3cbcd491f36019 100644 --- a/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.h +++ b/packages/react-native/Libraries/WebPerformance/PerformanceEntryReporter.h @@ -19,6 +19,8 @@ #include "BoundedConsumableBuffer.h" #include "NativePerformanceObserver.h" +#include + namespace facebook::react { struct PerformanceEntryHash { @@ -67,7 +69,7 @@ enum class PerformanceEntryType { constexpr size_t NUM_PERFORMANCE_ENTRY_TYPES = (size_t)PerformanceEntryType::_COUNT; -class PerformanceEntryReporter : public EventLogger { +class PerformanceEntryReporter : public EventLogger, public UIManagerMountHook { public: PerformanceEntryReporter(const PerformanceEntryReporter&) = delete; void operator=(const PerformanceEntryReporter&) = delete; @@ -142,7 +144,11 @@ class PerformanceEntryReporter : public EventLogger { EventTag onEventStart(std::string_view name) override; void onEventDispatch(EventTag tag) override; - void onEventEnd(EventTag tag) override; + void onEventDispatchEnd(EventTag tag) override; + + void shadowTreeDidMount( + const RootShadowNode::Shared& rootShadowNode, + double mountTime) noexcept override; const std::unordered_map& getEventCounts() const { return eventCounts_; @@ -152,6 +158,12 @@ class PerformanceEntryReporter : public EventLogger { timeStampProvider_ = provider; } + void setIsReportingEventPaintTime(bool isReportingEventPaintTime); + + bool isReportingEventPaintTime() const { + return isReportingEventPaintTime_; + } + private: std::optional> callback_; @@ -164,7 +176,8 @@ class PerformanceEntryReporter : public EventLogger { struct EventEntry { std::string_view name; double startTime{0.0}; - double dispatchTime{0.0}; + double processingStartTime{0.0}; + double processingEndTime{0.0}; }; // Registry to store the events that are currently ongoing. @@ -176,6 +189,10 @@ class PerformanceEntryReporter : public EventLogger { std::function timeStampProvider_ = nullptr; + // When set to true, the events end will be corresponding to the "paint" time, + // instead of processing end + bool isReportingEventPaintTime_ = false; + mutable std::mutex nameLookupMutex_; static EventTag sCurrentEventTag_; diff --git a/packages/react-native/Libraries/WebPerformance/__mocks__/NativePerformanceObserver.js b/packages/react-native/Libraries/WebPerformance/__mocks__/NativePerformanceObserver.js index dd0fd1acb7f537..4da3bad16688f2 100644 --- a/packages/react-native/Libraries/WebPerformance/__mocks__/NativePerformanceObserver.js +++ b/packages/react-native/Libraries/WebPerformance/__mocks__/NativePerformanceObserver.js @@ -123,6 +123,13 @@ const NativePerformanceObserverMock: NativePerformanceObserver = { RawPerformanceEntryTypeValues.EVENT, ]; }, + + isReportingEventPaintTime: (): boolean => { + return false; + }, + setIsReportingEventPaintTime: ( + isReportingEventPaintTime: boolean, + ): void => {}, }; export default NativePerformanceObserverMock; diff --git a/packages/react-native/ReactCommon/react/renderer/core/EventLogger.h b/packages/react-native/ReactCommon/react/renderer/core/EventLogger.h index 3a2863ba9d7d58..708f5e2cb280ac 100644 --- a/packages/react-native/ReactCommon/react/renderer/core/EventLogger.h +++ b/packages/react-native/ReactCommon/react/renderer/core/EventLogger.h @@ -37,7 +37,7 @@ class EventLogger { /* * Called when event finishes being dispatched */ - virtual void onEventEnd(EventTag tag) = 0; + virtual void onEventDispatchEnd(EventTag tag) = 0; }; void setEventLogger(EventLogger* eventLogger); diff --git a/packages/react-native/ReactCommon/react/renderer/core/EventQueueProcessor.cpp b/packages/react-native/ReactCommon/react/renderer/core/EventQueueProcessor.cpp index b562e0e8768575..dd3245ffb9cff1 100644 --- a/packages/react-native/ReactCommon/react/renderer/core/EventQueueProcessor.cpp +++ b/packages/react-native/ReactCommon/react/renderer/core/EventQueueProcessor.cpp @@ -77,7 +77,7 @@ void EventQueueProcessor::flushEvents( } if (eventLogger != nullptr) { - eventLogger->onEventEnd(event.loggingTag); + eventLogger->onEventDispatchEnd(event.loggingTag); } if (event.category == RawEvent::Category::ContinuousStart) {