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
This commit is contained in:
Ruslan Lesiutin
2025-03-04 08:10:41 -08:00
committed by Facebook GitHub Bot
parent 71fbf51979
commit df4433c40e
5 changed files with 104 additions and 86 deletions
@@ -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(
@@ -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;
@@ -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<TraceEvent> buffer_;
std::mutex mutex_;
};
@@ -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<std::chrono::microseconds>(
@@ -49,6 +53,7 @@ TraceEventProfileChunk::CPUProfile::Node convertToTraceEventProfileNode(
void emitSingleProfileChunk(
PerformanceTracer& performanceTracer,
std::vector<folly::dynamic>& 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<void(const folly::dynamic& traceEventsChunk)>&
notificationCallback,
uint16_t traceEventChunkSize,
uint16_t profileChunkSize) {
std::vector<RuntimeSamplingProfile::Sample> runtimeSamples =
profile.getSamples();
@@ -85,11 +93,13 @@ RuntimeSamplingProfileTraceEventSerializer::serializeAndBuffer(
return;
}
std::vector<folly::dynamic> 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
@@ -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<void(const folly::dynamic& traceEventsChunk)>&
notificationCallback,
uint16_t traceEventChunkSize,
uint16_t profileChunkSize = 100);
};