Refactor TraceEvent format (#48269)

Summary:
Pull Request resolved: https://github.com/facebook/react-native/pull/48269

# Changelog: [Internal]

I've noticed that our definition of Trace Event is different from the one that is defined in Google's doc / V8 / Chrome. This has some flaws:
* It creates fragmentation, like with custom track ids or with mocked process ids.
* Current implementation is strict the relationship between `performance.mark()`, `performance.measure` APIs and Instant, Complete Trace Events. Basically only something recorded with `performance.mark` can be an instant trace event.

This should unblock recording custom trace events inside `PerformanceTracer`, such as when tracing started and others. Same could be said about events related to CPU profiling from Hermes, which will be based on these APIs.

This is the pre-requisite for next diff that will add emitting `TracingStartedInPage` event. With this event, the trace should look similar to the one recorded in the browser, and Timings / Main tracks no longer should be registered manually.

Reviewed By: huntie

Differential Revision: D67207107

fbshipit-source-id: fd7f55dd82167c14a63c2d93aaa649072c5a2a2c
This commit is contained in:
Ruslan Lesiutin
2024-12-16 15:19:16 -08:00
committed by Facebook GitHub Bot
parent 4368368ef5
commit 03a1246c35
2 changed files with 148 additions and 57 deletions
@@ -49,12 +49,11 @@ bool PerformanceTracer::stopTracingAndCollectEvents(
tracing_ = false;
if (buffer_.empty()) {
customTrackIdMap_.clear();
return true;
}
auto traceEvents = folly::dynamic::array();
auto savedBuffer = std::move(buffer_);
buffer_.clear();
// Register "Main" process
traceEvents.push_back(folly::dynamic::object(
@@ -69,27 +68,29 @@ bool PerformanceTracer::stopTracingAndCollectEvents(
"cat", "__metadata")("name", "thread_name")("ph", "M")("pid", PID)(
"tid", USER_TIMINGS_DEFAULT_TRACK)("ts", 0));
auto customTrackIdMap = getCustomTracks(savedBuffer);
for (const auto& [trackName, trackId] : customTrackIdMap) {
for (const auto& [trackName, trackId] : customTrackIdMap_) {
// Register custom tracks
traceEvents.push_back(folly::dynamic::object(
"args", folly::dynamic::object("name", trackName))("cat", "__metadata")(
"name", "thread_name")("ph", "M")("pid", PID)("tid", trackId)("ts", 0));
}
for (auto& event : savedBuffer) {
for (auto event : buffer_) {
// Emit trace events
traceEvents.push_back(serializeTraceEvent(event, customTrackIdMap));
traceEvents.push_back(serializeTraceEvent(event));
if (traceEvents.size() >= 1000) {
resultCallback(traceEvents);
traceEvents = folly::dynamic::array();
}
}
customTrackIdMap_.clear();
buffer_.clear();
if (traceEvents.size() >= 1) {
resultCallback(traceEvents);
}
return true;
}
@@ -100,8 +101,15 @@ void PerformanceTracer::reportMark(
if (!tracing_) {
return;
}
buffer_.push_back(TraceEvent{
.type = TraceEventType::MARK, .name = std::string(name), .start = start});
TraceEventBase* event = new InstantTraceEvent{
std::string(name),
std::vector{TraceEventCategory::UserTiming},
start,
PID, // FIXME: This should be real process ID.
USER_TIMINGS_DEFAULT_TRACK, // FIXME: This should be real thread ID.
};
buffer_.push_back(event);
}
void PerformanceTracer::reportMeasure(
@@ -114,62 +122,85 @@ void PerformanceTracer::reportMeasure(
return;
}
std::optional<std::string> track;
uint64_t threadId =
USER_TIMINGS_DEFAULT_TRACK; // FIXME: This should be real thread ID.
if (trackMetadata.has_value()) {
track = trackMetadata.value().track;
std::string trackName = trackMetadata.value().track;
if (!customTrackIdMap_.contains(trackName)) {
uint64_t trackId =
USER_TIMINGS_DEFAULT_TRACK + customTrackIdMap_.size() + 1;
threadId = trackId;
customTrackIdMap_.emplace(trackName, trackId);
}
}
buffer_.push_back(TraceEvent{
.type = TraceEventType::MEASURE,
.name = std::string(name),
.start = start,
.duration = duration,
.track = track});
TraceEventBase* event = new CompleteTraceEvent{
std::string(name),
std::vector{TraceEventCategory::UserTiming},
start,
PID, // FIXME: This should be real process ID.
threadId, // FIXME: This should be real thread ID.
duration};
buffer_.push_back(event);
}
std::unordered_map<std::string, uint32_t> PerformanceTracer::getCustomTracks(
std::vector<TraceEvent>& events) {
std::unordered_map<std::string, uint32_t> trackIdMap;
std::string PerformanceTracer::serializeTraceEventCategories(
TraceEventBase* event) const {
std::string result;
uint32_t nextTrack = USER_TIMINGS_DEFAULT_TRACK + 1;
for (auto& event : events) {
// Custom tracks are only supported by User Timing "measure" events
if (event.type != TraceEventType::MEASURE) {
continue;
for (const auto& category : event->categories) {
switch (category) {
case TraceEventCategory::UserTiming:
result += "blink.user_timing";
break;
case TraceEventCategory::TimelineEvent:
result += "disabled-by-default-devtools.timeline";
break;
default:
throw std::runtime_error("Unknown trace event category");
}
if (event.track.has_value() && !trackIdMap.contains(event.track.value())) {
auto trackId = nextTrack++;
trackIdMap[event.track.value()] = trackId;
}
result += ",";
}
return trackIdMap;
if (result.length() > 0) {
result.pop_back();
}
return result;
}
folly::dynamic PerformanceTracer::serializeTraceEvent(
TraceEvent& event,
std::unordered_map<std::string, uint32_t>& customTrackIdMap) const {
TraceEventBase* event) const {
folly::dynamic result = folly::dynamic::object;
result["args"] = folly::dynamic::object();
result["cat"] = "blink.user_timing";
result["name"] = event.name;
result["pid"] = PID;
result["ts"] = event.start;
result["name"] = event->name;
result["cat"] = serializeTraceEventCategories(event);
result["args"] = event->args;
result["ts"] = event->timestamp;
result["pid"] = event->processId;
result["tid"] = event->threadId;
switch (event.type) {
case TraceEventType::MARK:
switch (event->type) {
case TraceEventType::Instant:
result["ph"] = "I";
result["tid"] = USER_TIMINGS_DEFAULT_TRACK;
break;
case TraceEventType::MEASURE:
result["dur"] = event.duration;
case TraceEventType::Complete: {
result["ph"] = "X";
result["tid"] = event.track.has_value()
? customTrackIdMap[event.track.value()]
: USER_TIMINGS_DEFAULT_TRACK;
auto completeEvent = static_cast<CompleteTraceEvent*>(event);
result["dur"] = completeEvent->duration;
break;
}
default:
throw std::runtime_error("Unknown trace event type");
}
return result;
@@ -22,16 +22,78 @@ namespace facebook::react::jsinspector_modern {
// design is copied from earlier FuseboxTracer prototype).
enum class TraceEventType {
MARK = 1,
MEASURE = 2,
Instant,
Complete,
};
struct TraceEvent {
TraceEventType type;
enum class TraceEventCategory {
UserTiming,
TimelineEvent,
};
/*
* Based on the out-of-date "Trace Event Format" document from Google and our
* findings while reverse engineering the contract between Chrome and Chrome
* DevTools.
* https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview?pli=1&tab=t.0#heading=h.yr4qxyxotyw
*/
struct TraceEventBase {
std::string name;
uint64_t start;
uint64_t duration = 0;
std::optional<std::string> track;
std::vector<TraceEventCategory> categories;
TraceEventType type;
uint64_t timestamp;
uint64_t processId;
uint64_t threadId;
folly::dynamic args = folly::dynamic::object();
};
template <TraceEventType T>
struct TraceEvent : public TraceEventBase {
TraceEvent(
std::string name,
std::vector<TraceEventCategory> categories,
uint64_t timestamp,
uint64_t processId,
uint64_t threadId)
: TraceEventBase{
std::move(name),
std::move(categories),
T,
timestamp,
processId,
threadId} {}
};
struct CompleteTraceEvent : public TraceEvent<TraceEventType::Complete> {
uint64_t duration;
CompleteTraceEvent(
std::string name,
std::vector<TraceEventCategory> categories,
uint64_t timestamp,
uint64_t processId,
uint64_t threadId,
uint64_t duration)
: TraceEvent<
TraceEventType::
Complete>{std::move(name), std::move(categories), timestamp, processId, threadId},
duration(duration) {}
};
struct InstantTraceEvent : public TraceEvent<TraceEventType::Instant> {
InstantTraceEvent(
std::string name,
std::vector<TraceEventCategory> categories,
uint64_t timestamp,
uint64_t processId,
uint64_t threadId)
: TraceEvent<TraceEventType::Instant>{
std::move(name),
std::move(categories),
timestamp,
processId,
threadId} {}
};
/**
@@ -83,14 +145,12 @@ class PerformanceTracer {
PerformanceTracer& operator=(const PerformanceTracer&) = delete;
~PerformanceTracer() = default;
std::unordered_map<std::string, uint32_t> getCustomTracks(
std::vector<TraceEvent>& events);
folly::dynamic serializeTraceEvent(
TraceEvent& event,
std::unordered_map<std::string, uint32_t>& customTrackIdMap) const;
std::string serializeTraceEventCategories(TraceEventBase* event) const;
folly::dynamic serializeTraceEvent(TraceEventBase* event) const;
bool tracing_{false};
std::vector<TraceEvent> buffer_;
std::unordered_map<std::string, uint64_t> customTrackIdMap_;
std::vector<TraceEventBase*> buffer_;
std::mutex mutex_;
};