From df4433c40e4ea2047b258374eb47ed037b6a5909 Mon Sep 17 00:00:00 2001 From: Ruslan Lesiutin Date: Tue, 4 Mar 2025 08:10:41 -0800 Subject: [PATCH] Serialize and send Profile trace events after emitting the buffer (#49794) Summary: Pull Request resolved: https://github.com/facebook/react-native/pull/49794 # Changelog: [Internal] Before, we would store all User Timings and Timeline Events in the PerformanceTracer's buffer, and then add Profile event to it as well. On larger apps, the amount of events buffered could reach ~100k, which inevitably would cause OOM. With this approach, we will flush out buffered events from PerformanceTracer first, then do JavaScript Profile serialization, then send it over CDP straight away. Reviewed By: huntie Differential Revision: D70395982 fbshipit-source-id: 2c17abba421fa9c4afc4d4ca36afd98b1db50905 --- .../jsinspector-modern/TracingAgent.cpp | 23 ++--- .../tracing/PerformanceTracer.cpp | 88 ++++++++----------- .../tracing/PerformanceTracer.h | 35 ++++---- ...imeSamplingProfileTraceEventSerializer.cpp | 39 ++++++-- ...ntimeSamplingProfileTraceEventSerializer.h | 5 +- 5 files changed, 104 insertions(+), 86 deletions(-) diff --git a/packages/react-native/ReactCommon/jsinspector-modern/TracingAgent.cpp b/packages/react-native/ReactCommon/jsinspector-modern/TracingAgent.cpp index a57ce54bef2..ca3554f2bf9 100644 --- a/packages/react-native/ReactCommon/jsinspector-modern/TracingAgent.cpp +++ b/packages/react-native/ReactCommon/jsinspector-modern/TracingAgent.cpp @@ -61,12 +61,8 @@ bool TracingAgent::handleRequest(const cdp::PreparsedRequest& req) { return true; } - instanceAgent_->stopTracing(); - tracing::RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer( - PerformanceTracer::getInstance(), - instanceAgent_->collectTracingProfile().getRuntimeSamplingProfile(), - instanceTracingStartTimestamp_); + instanceAgent_->stopTracing(); bool correctlyStopped = PerformanceTracer::getInstance().stopTracing(); if (!correctlyStopped) { frontendChannel_(cdp::jsonError( @@ -80,12 +76,19 @@ bool TracingAgent::handleRequest(const cdp::PreparsedRequest& req) { // Send response to Tracing.end request. frontendChannel_(cdp::jsonResult(req.id)); + auto dataCollectedCallback = [this](const folly::dynamic& eventsChunk) { + frontendChannel_(cdp::jsonNotification( + "Tracing.dataCollected", + folly::dynamic::object("value", eventsChunk))); + }; PerformanceTracer::getInstance().collectEvents( - [this](const folly::dynamic& eventsChunk) { - frontendChannel_(cdp::jsonNotification( - "Tracing.dataCollected", - folly::dynamic::object("value", eventsChunk))); - }, + dataCollectedCallback, TRACE_EVENT_CHUNK_SIZE); + + tracing::RuntimeSamplingProfileTraceEventSerializer::serializeAndNotify( + PerformanceTracer::getInstance(), + instanceAgent_->collectTracingProfile().getRuntimeSamplingProfile(), + instanceTracingStartTimestamp_, + dataCollectedCallback, TRACE_EVENT_CHUNK_SIZE); frontendChannel_(cdp::jsonNotification( diff --git a/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.cpp b/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.cpp index a241f53737b..1768fd6f6a4 100644 --- a/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.cpp +++ b/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.cpp @@ -83,7 +83,6 @@ bool PerformanceTracer::stopTracing() { }); performanceMeasureCount_ = 0; - profileCount_ = 0; tracing_ = false; return true; } @@ -243,56 +242,6 @@ void PerformanceTracer::reportThread(uint64_t id, const std::string& name) { }); } -uint16_t PerformanceTracer::reportRuntimeProfile( - uint64_t threadId, - uint64_t eventUnixTimestamp) { - std::lock_guard lock(mutex_); - if (!tracing_) { - throw std::runtime_error( - "Runtime Profile should only be reported when Tracing is enabled"); - } - - ++profileCount_; - // CDT prioritizes event timestamp over startTime metadata field. - // https://fburl.com/lo764pf4 - buffer_.push_back(TraceEvent{ - .id = profileCount_, - .name = "Profile", - .cat = "disabled-by-default-v8.cpu_profiler", - .ph = 'P', - .ts = eventUnixTimestamp, - .pid = processId_, - .tid = threadId, - .args = folly::dynamic::object( - "data", folly ::dynamic::object("startTime", eventUnixTimestamp)), - }); - - return profileCount_; -} - -void PerformanceTracer::reportRuntimeProfileChunk( - uint16_t profileId, - uint64_t threadId, - uint64_t eventUnixTimestamp, - const tracing::TraceEventProfileChunk& traceEventProfileChunk) { - std::lock_guard lock(mutex_); - if (!tracing_) { - return; - } - - buffer_.push_back(TraceEvent{ - .id = profileId, - .name = "ProfileChunk", - .cat = "disabled-by-default-v8.cpu_profiler", - .ph = 'P', - .ts = eventUnixTimestamp, - .pid = processId_, - .tid = threadId, - .args = - folly::dynamic::object("data", traceEventProfileChunk.asDynamic()), - }); -} - void PerformanceTracer::reportEventLoopTask(uint64_t start, uint64_t end) { if (!tracing_) { return; @@ -314,6 +263,43 @@ void PerformanceTracer::reportEventLoopTask(uint64_t start, uint64_t end) { }); } +folly::dynamic PerformanceTracer::getSerializedRuntimeProfileTraceEvent( + uint64_t threadId, + uint16_t profileId, + uint64_t eventUnixTimestamp) { + // CDT prioritizes event timestamp over startTime metadata field. + // https://fburl.com/lo764pf4 + return serializeTraceEvent(TraceEvent{ + .id = profileId, + .name = "Profile", + .cat = "disabled-by-default-v8.cpu_profiler", + .ph = 'P', + .ts = eventUnixTimestamp, + .pid = processId_, + .tid = threadId, + .args = folly::dynamic::object( + "data", folly ::dynamic::object("startTime", eventUnixTimestamp)), + }); +} + +folly::dynamic PerformanceTracer::getSerializedRuntimeProfileChunkTraceEvent( + uint16_t profileId, + uint64_t threadId, + uint64_t eventUnixTimestamp, + const tracing::TraceEventProfileChunk& traceEventProfileChunk) { + return serializeTraceEvent(TraceEvent{ + .id = profileId, + .name = "ProfileChunk", + .cat = "disabled-by-default-v8.cpu_profiler", + .ph = 'P', + .ts = eventUnixTimestamp, + .pid = processId_, + .tid = threadId, + .args = + folly::dynamic::object("data", traceEventProfileChunk.asDynamic()), + }); +} + folly::dynamic PerformanceTracer::serializeTraceEvent(TraceEvent event) const { folly::dynamic result = folly::dynamic::object; diff --git a/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.h b/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.h index 0c5f29156f8..17c3f4d73d8 100644 --- a/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.h +++ b/packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.h @@ -95,27 +95,31 @@ class PerformanceTracer { */ void reportJavaScriptThread(); - /** - * Record a corresponding Profile Trace Event. - * \return the id of the profile, should be used to linking profile chunks. - */ - uint16_t reportRuntimeProfile(uint64_t threadId, uint64_t eventUnixTimestamp); - - /** - * Record a corresponding ProfileChunk Trace Event. - */ - void reportRuntimeProfileChunk( - uint16_t profileId, - uint64_t threadId, - uint64_t eventUnixTimestamp, - const tracing::TraceEventProfileChunk& traceEventProfileChunk); - /** * Record an Event Loop tick, which will be represented as an Event Loop task * on a timeline view and grouped with JavaScript samples. */ void reportEventLoopTask(uint64_t start, uint64_t end); + /** + * Create and serialize Profile Trace Event. + * \return serialized Trace Event that represents a Profile for CDT. + */ + folly::dynamic getSerializedRuntimeProfileTraceEvent( + uint64_t threadId, + uint16_t profileId, + uint64_t eventUnixTimestamp); + + /** + * Create and serialize ProfileChunk Trace Event. + * \return serialized Trace Event that represents a Profile Chunk for CDT. + */ + folly::dynamic getSerializedRuntimeProfileChunkTraceEvent( + uint16_t profileId, + uint64_t threadId, + uint64_t eventUnixTimestamp, + const tracing::TraceEventProfileChunk& traceEventProfileChunk); + private: PerformanceTracer(); PerformanceTracer(const PerformanceTracer&) = delete; @@ -127,7 +131,6 @@ class PerformanceTracer { bool tracing_{false}; uint64_t processId_; uint32_t performanceMeasureCount_{0}; - uint16_t profileCount_{0}; std::vector buffer_; std::mutex mutex_; }; diff --git a/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.cpp b/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.cpp index 61f85386c4f..c203e6da85e 100644 --- a/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.cpp +++ b/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.cpp @@ -12,6 +12,10 @@ namespace facebook::react::jsinspector_modern::tracing { namespace { +// Right now we only emit single Profile. We might revisit this decision in the +// future, once we support multiple VMs being sampled at the same time. +const uint16_t PROFILE_ID = 1; + uint64_t formatTimePointToUnixTimestamp( std::chrono::steady_clock::time_point timestamp) { return std::chrono::duration_cast( @@ -49,6 +53,7 @@ TraceEventProfileChunk::CPUProfile::Node convertToTraceEventProfileNode( void emitSingleProfileChunk( PerformanceTracer& performanceTracer, + std::vector& buffer, uint16_t profileId, uint64_t threadId, uint64_t chunkTimestamp, @@ -61,23 +66,26 @@ void emitSingleProfileChunk( traceEventNodes.push_back(convertToTraceEventProfileNode(node)); } - performanceTracer.reportRuntimeProfileChunk( + buffer.push_back(performanceTracer.getSerializedRuntimeProfileChunkTraceEvent( profileId, threadId, chunkTimestamp, TraceEventProfileChunk{ TraceEventProfileChunk::CPUProfile{traceEventNodes, samples}, TraceEventProfileChunk::TimeDeltas{timeDeltas}, - }); + })); } } // namespace /* static */ void -RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer( +RuntimeSamplingProfileTraceEventSerializer::serializeAndNotify( PerformanceTracer& performanceTracer, const RuntimeSamplingProfile& profile, std::chrono::steady_clock::time_point tracingStartTime, + const std::function& + notificationCallback, + uint16_t traceEventChunkSize, uint16_t profileChunkSize) { std::vector runtimeSamples = profile.getSamples(); @@ -85,11 +93,13 @@ RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer( return; } + std::vector buffer; + uint64_t chunkThreadId = runtimeSamples.front().getThreadId(); uint64_t tracingStartUnixTimestamp = formatTimePointToUnixTimestamp(tracingStartTime); - uint16_t profileId = performanceTracer.reportRuntimeProfile( - chunkThreadId, tracingStartUnixTimestamp); + buffer.push_back(performanceTracer.getSerializedRuntimeProfileTraceEvent( + chunkThreadId, PROFILE_ID, tracingStartUnixTimestamp)); uint32_t nodeCount = 0; auto* rootNode = new ProfileTreeNode( @@ -148,7 +158,8 @@ RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer( if (chunkThreadId != sampleThreadId) { emitSingleProfileChunk( performanceTracer, - profileId, + buffer, + PROFILE_ID, chunkThreadId, chunkTimestamp, nodesInThisChunk, @@ -203,7 +214,8 @@ RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer( if (samplesInThisChunk.size() == profileChunkSize) { emitSingleProfileChunk( performanceTracer, - profileId, + buffer, + PROFILE_ID, chunkThreadId, chunkTimestamp, nodesInThisChunk, @@ -214,18 +226,29 @@ RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer( samplesInThisChunk.clear(); timeDeltasInThisChunk.clear(); } + + if (buffer.size() == traceEventChunkSize) { + notificationCallback(folly::dynamic::array(buffer.begin(), buffer.end())); + buffer.clear(); + } } if (!samplesInThisChunk.empty()) { emitSingleProfileChunk( performanceTracer, - profileId, + buffer, + PROFILE_ID, chunkThreadId, chunkTimestamp, nodesInThisChunk, samplesInThisChunk, timeDeltasInThisChunk); } + + if (!buffer.empty()) { + notificationCallback(folly::dynamic::array(buffer.begin(), buffer.end())); + buffer.clear(); + } } } // namespace facebook::react::jsinspector_modern::tracing diff --git a/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.h b/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.h index 271d0a7463a..7c483ebe8bd 100644 --- a/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.h +++ b/packages/react-native/ReactCommon/jsinspector-modern/tracing/RuntimeSamplingProfileTraceEventSerializer.h @@ -20,10 +20,13 @@ class RuntimeSamplingProfileTraceEventSerializer { public: RuntimeSamplingProfileTraceEventSerializer() = delete; - static void serializeAndBuffer( + static void serializeAndNotify( PerformanceTracer& performanceTracer, const RuntimeSamplingProfile& profile, std::chrono::steady_clock::time_point tracingStartTime, + const std::function& + notificationCallback, + uint16_t traceEventChunkSize, uint16_t profileChunkSize = 100); };