Refactor tracing in performance.mark and performance.measure

Summary:
Changelog: [internal]

This refactors some code in the performance API and Perfetto to avoid doing unnecessary work when not tracing (e.g.: string manipulation for tracks).

It also reduces the cost of logging marks/measures to tracing backends if not actively tracing (e.g.: moving the check to outside the lock).

Differential Revision: D69246772

Author: rubennorte

packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.cpp

@@ -72,6 +72,12 @@ bool PerformanceTracer::stopTracing() {
   return true;
 }
 
+bool PerformanceTracer::isTracing() const {
+  // This is not thread safe but it's only a performance optimization. The call
+  // to report marks and measures is already thread safe.
+  return tracing_;
+}
+
 void PerformanceTracer::collectEvents(
     const std::function<void(const folly::dynamic& eventsChunk)>&
         resultCallback,
@@ -102,6 +108,10 @@ void PerformanceTracer::collectEvents(
 void PerformanceTracer::reportMark(
     const std::string_view& name,
     uint64_t start) {
+  if (!tracing_) {
+    return;
+  }
+
   std::lock_guard<std::mutex> lock(mutex_);
   if (!tracing_) {
     return;
@@ -122,6 +132,10 @@ void PerformanceTracer::reportMeasure(
     uint64_t start,
     uint64_t duration,
     const std::optional<DevToolsTrackEntryPayload>& trackMetadata) {
+  if (!tracing_) {
+    return;
+  }
+
   std::lock_guard<std::mutex> lock(mutex_);
   if (!tracing_) {
     return;

packages/react-native/ReactCommon/jsinspector-modern/tracing/PerformanceTracer.h

@@ -40,6 +40,13 @@ class PerformanceTracer {
    */
   bool stopTracing();
 
+  /**
+   * Returns whether the tracer is currently tracing. This can be useful to
+   * avoid doing expensive work (like formatting strings) if tracing is not
+   * enabled.
+   */
+  bool isTracing() const;
+
   /**
    * Flush out buffered CDP Trace Events using the given callback.
    */

packages/react-native/ReactCommon/react/nativemodule/webperformance/NativePerformance.cpp

@@ -14,21 +14,15 @@
 #include <cxxreact/JSExecutor.h>
 #include <cxxreact/ReactMarker.h>
 #include <jsi/instrumentation.h>
-#include <jsinspector-modern/tracing/CdpTracing.h>
 #include <react/performance/timeline/PerformanceEntryReporter.h>
 #include <react/performance/timeline/PerformanceObserver.h>
-#include <reactperflogger/ReactPerfettoLogger.h>
 
 #include "NativePerformance.h"
 
 #ifdef RN_DISABLE_OSS_PLUGIN_HEADER
 #include "Plugins.h"
 #endif
 
-#ifdef WITH_PERFETTO
-#include <reactperflogger/ReactPerfetto.h>
-#endif
-
 std::shared_ptr<facebook::react::TurboModule> NativePerformanceModuleProvider(
     std::shared_ptr<facebook::react::CallInvoker> jsInvoker) {
   return std::make_shared<facebook::react::NativePerformance>(
@@ -39,33 +33,6 @@ namespace facebook::react {
 
 namespace {
 
-#if defined(__clang__)
-#define NO_DESTROY [[clang::no_destroy]]
-#else
-#define NO_DESTROY
-#endif
-
-NO_DESTROY const std::string TRACK_PREFIX = "Track:";
-
-std::tuple<std::optional<std::string>, std::string_view> parseTrackName(
-    const std::string& name) {
-  // Until there's a standard way to pass through track information, parse it
-  // manually, e.g., "Track:Foo:Event name"
-  // https://github.com/w3c/user-timing/issues/109
-  std::optional<std::string> trackName;
-  std::string_view eventName(name);
-  if (name.starts_with(TRACK_PREFIX)) {
-    const auto trackNameDelimiter = name.find(':', TRACK_PREFIX.length());
-    if (trackNameDelimiter != std::string::npos) {
-      trackName = name.substr(
-          TRACK_PREFIX.length(), trackNameDelimiter - TRACK_PREFIX.length());
-      eventName = std::string_view(name).substr(trackNameDelimiter + 1);
-    }
-  }
-
-  return std::make_tuple(trackName, eventName);
-}
-
 class PerformanceObserverWrapper : public jsi::NativeState {
  public:
   explicit PerformanceObserverWrapper(
@@ -103,11 +70,7 @@ std::shared_ptr<PerformanceObserver> tryGetObserver(
 } // namespace
 
 NativePerformance::NativePerformance(std::shared_ptr<CallInvoker> jsInvoker)
-    : NativePerformanceCxxSpec(std::move(jsInvoker)) {
-#ifdef WITH_PERFETTO
-  initializePerfetto();
-#endif
-}
+    : NativePerformanceCxxSpec(std::move(jsInvoker)) {}
 
 double NativePerformance::now(jsi::Runtime& /*rt*/) {
   return JSExecutor::performanceNow();
@@ -117,12 +80,8 @@ double NativePerformance::markWithResult(
     jsi::Runtime& rt,
     std::string name,
     std::optional<double> startTime) {
-  auto [trackName, eventName] = parseTrackName(name);
   auto entry =
       PerformanceEntryReporter::getInstance()->reportMark(name, startTime);
-
-  ReactPerfettoLogger::mark(eventName, entry.startTime, trackName);
-
   return entry.startTime;
 }
 
@@ -134,26 +93,8 @@ std::tuple<double, double> NativePerformance::measureWithResult(
     std::optional<double> duration,
     std::optional<std::string> startMark,
     std::optional<std::string> endMark) {
-  auto [trackName, eventName] = parseTrackName(name);
-
-  std::optional<jsinspector_modern::DevToolsTrackEntryPayload> trackMetadata;
-
-  if (trackName.has_value()) {
-    trackMetadata = {.track = trackName.value()};
-  }
-
   auto entry = PerformanceEntryReporter::getInstance()->reportMeasure(
-      eventName,
-      startTime,
-      endTime,
-      duration,
-      startMark,
-      endMark,
-      trackMetadata);
-
-  ReactPerfettoLogger::measure(
-      eventName, entry.startTime, entry.startTime + entry.duration, trackName);
-
+      name, startTime, endTime, duration, startMark, endMark);
   return std::tuple{entry.startTime, entry.duration};
 }
 

packages/react-native/ReactCommon/react/performance/timeline/PerformanceEntryReporter.cpp

@@ -10,6 +10,11 @@
 #include <cxxreact/JSExecutor.h>
 #include <jsinspector-modern/tracing/PerformanceTracer.h>
 #include <react/featureflags/ReactNativeFeatureFlags.h>
+#include <reactperflogger/ReactPerfettoLogger.h>
+
+#ifdef WITH_PERFETTO
+#include <reactperflogger/ReactPerfetto.h>
+#endif
 
 namespace facebook::react {
 
@@ -33,6 +38,33 @@ uint64_t timestampToMicroseconds(DOMHighResTimeStamp timestamp) {
   return static_cast<uint64_t>(timestamp * 1000);
 }
 
+#if defined(__clang__)
+#define NO_DESTROY [[clang::no_destroy]]
+#else
+#define NO_DESTROY
+#endif
+
+NO_DESTROY const std::string TRACK_PREFIX = "Track:";
+
+std::tuple<std::optional<std::string>, std::string_view> parseTrackName(
+    const std::string& name) {
+  // Until there's a standard way to pass through track information, parse it
+  // manually, e.g., "Track:Foo:Event name"
+  // https://github.com/w3c/user-timing/issues/109
+  std::optional<std::string> trackName;
+  std::string_view eventName(name);
+  if (name.starts_with(TRACK_PREFIX)) {
+    const auto trackNameDelimiter = name.find(':', TRACK_PREFIX.length());
+    if (trackNameDelimiter != std::string::npos) {
+      trackName = name.substr(
+          TRACK_PREFIX.length(), trackNameDelimiter - TRACK_PREFIX.length());
+      eventName = std::string_view(name).substr(trackNameDelimiter + 1);
+    }
+  }
+
+  return std::make_tuple(trackName, eventName);
+}
+
 } // namespace
 
 std::shared_ptr<PerformanceEntryReporter>&
@@ -42,7 +74,11 @@ PerformanceEntryReporter::getInstance() {
 }
 
 PerformanceEntryReporter::PerformanceEntryReporter()
-    : observerRegistry_(std::make_unique<PerformanceObserverRegistry>()) {}
+    : observerRegistry_(std::make_unique<PerformanceObserverRegistry>()) {
+#ifdef WITH_PERFETTO
+  initializePerfetto();
+#endif
+}
 
 DOMHighResTimeStamp PerformanceEntryReporter::getCurrentTimeStamp() const {
   return timeStampProvider_ != nullptr ? timeStampProvider_()
@@ -135,26 +171,28 @@ void PerformanceEntryReporter::clearEntries(
 PerformanceEntry PerformanceEntryReporter::reportMark(
     const std::string& name,
     const std::optional<DOMHighResTimeStamp>& startTime) {
+  // Resolve timings
   auto startTimeVal = startTime ? *startTime : getCurrentTimeStamp();
   const auto entry = PerformanceEntry{
       .name = name,
       .entryType = PerformanceEntryType::MARK,
       .startTime = startTimeVal};
 
+  traceMark(entry);
+
+  // Add to buffers & notify observers
   {
     std::unique_lock lock(buffersMutex_);
     markBuffer_.add(entry);
   }
 
-  jsinspector_modern::PerformanceTracer::getInstance().reportMark(
-      name, timestampToMicroseconds(startTimeVal));
-
   observerRegistry_->queuePerformanceEntry(entry);
+
   return entry;
 }
 
 PerformanceEntry PerformanceEntryReporter::reportMeasure(
-    const std::string_view& name,
+    const std::string& name,
     DOMHighResTimeStamp startTime,
     DOMHighResTimeStamp endTime,
     const std::optional<DOMHighResTimeStamp>& duration,
@@ -181,18 +219,16 @@ PerformanceEntry PerformanceEntryReporter::reportMeasure(
       .startTime = startTimeVal,
       .duration = durationVal};
 
+  traceMeasure(entry);
+
+  // Add to buffers & notify observers
   {
     std::unique_lock lock(buffersMutex_);
     measureBuffer_.add(entry);
   }
 
-  jsinspector_modern::PerformanceTracer::getInstance().reportMeasure(
-      name,
-      timestampToMicroseconds(startTimeVal),
-      timestampToMicroseconds(durationVal),
-      trackMetadata);
-
   observerRegistry_->queuePerformanceEntry(entry);
+
   return entry;
 }
 
@@ -257,4 +293,52 @@ void PerformanceEntryReporter::reportLongTask(
   observerRegistry_->queuePerformanceEntry(entry);
 }
 
+void PerformanceEntryReporter::traceMark(const PerformanceEntry& entry) const {
+  auto& performanceTracer =
+      jsinspector_modern::PerformanceTracer::getInstance();
+  if (ReactPerfettoLogger::isTracing() || performanceTracer.isTracing()) {
+    auto [trackName, eventName] = parseTrackName(entry.name);
+
+    if (performanceTracer.isTracing()) {
+      performanceTracer.reportMark(
+          entry.name, timestampToMicroseconds(entry.startTime));
+    }
+
+    if (ReactPerfettoLogger::isTracing()) {
+      ReactPerfettoLogger::mark(eventName, entry.startTime, trackName);
+    }
+  }
+}
+
+void PerformanceEntryReporter::traceMeasure(
+    const PerformanceEntry& entry) const {
+  auto& performanceTracer =
+      jsinspector_modern::PerformanceTracer::getInstance();
+  if (performanceTracer.isTracing() || ReactPerfettoLogger::isTracing()) {
+    auto [trackName, eventName] = parseTrackName(entry.name);
+
+    if (performanceTracer.isTracing()) {
+      std::optional<jsinspector_modern::DevToolsTrackEntryPayload>
+          trackMetadata;
+
+      if (trackName.has_value()) {
+        trackMetadata = {.track = trackName.value()};
+      }
+      performanceTracer.reportMeasure(
+          eventName,
+          timestampToMicroseconds(entry.startTime),
+          timestampToMicroseconds(entry.duration),
+          trackMetadata);
+    }
+
+    if (ReactPerfettoLogger::isTracing()) {
+      ReactPerfettoLogger::measure(
+          eventName,
+          entry.startTime,
+          entry.startTime + entry.duration,
+          trackName);
+    }
+  }
+}
+
 } // namespace facebook::react

packages/react-native/ReactCommon/react/performance/timeline/PerformanceEntryReporter.h

@@ -82,7 +82,7 @@ class PerformanceEntryReporter {
       const std::optional<DOMHighResTimeStamp>& startTime = std::nullopt);
 
   PerformanceEntry reportMeasure(
-      const std::string_view& name,
+      const std::string& name,
       double startTime,
       double endTime,
       const std::optional<double>& duration = std::nullopt,
@@ -148,6 +148,9 @@ class PerformanceEntryReporter {
     }
     throw std::logic_error("Unhandled PerformanceEntryType");
   }
+
+  void traceMark(const PerformanceEntry& entry) const;
+  void traceMeasure(const PerformanceEntry& entry) const;
 };
 
 } // namespace facebook::react

packages/react-native/ReactCommon/reactperflogger/reactperflogger/ReactPerfettoLogger.cpp

@@ -29,6 +29,14 @@ std::string toPerfettoTrackName(
 } // namespace
 #endif
 
+/* static */ bool ReactPerfettoLogger::isTracing() {
+#ifdef WITH_PERFETTO
+  return TRACE_EVENT_CATEGORY_ENABLED("react-native");
+#else
+  return false;
+#endif
+}
+
 /* static */ void ReactPerfettoLogger::measure(
     const std::string_view& eventName,
     double startTime,

packages/react-native/ReactCommon/reactperflogger/reactperflogger/ReactPerfettoLogger.h

@@ -20,6 +20,8 @@ namespace facebook::react {
  */
 class ReactPerfettoLogger {
  public:
+  static bool isTracing();
+
   static void mark(
       const std::string_view& eventName,
       double startTime,