Improve Network trace event field coverage (#53840)

Summary:
Pull Request resolved: #53840

After this diff, successful network events are displayed as fully hydrated timespans in the Performance panel network track, with all metadata needed to usefully populate the UI.

**Changes**

Adds:
- `"ResourceFinish"`: `encodedDataLength`, `decodedBodyLength`
- `"ResourceReceiveResponse"`: Populates `data.timing` members, which enables *"Request sent and waiting"* to be rendered correctly in the timeline.

Removes:

- `"ResourceWillSendRequest"` events — very rarely emitted by Chrome and are extraneous for our use case.

Changelog: [Internal]

Reviewed By: hoxyq

Differential Revision: D82636798

fbshipit-source-id: a4b0f0671b97aaadc279ac56d39fee0c95d4ddc7

Author: huntie

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

@@ -238,25 +238,6 @@ void PerformanceTracer::reportEventLoopMicrotasks(
   });
 }
 
-void PerformanceTracer::reportResourceWillSendRequest(
-    const std::string& devtoolsRequestId,
-    HighResTimeStamp start) {
-  if (!tracingAtomic_) {
-    return;
-  }
-
-  std::lock_guard<std::mutex> lock(mutex_);
-  if (!tracingAtomic_) {
-    return;
-  }
-
-  enqueueEvent(PerformanceTracerResourceWillSendRequest{
-      .requestId = devtoolsRequestId,
-      .start = start,
-      .threadId = getCurrentThreadId(),
-  });
-}
-
 void PerformanceTracer::reportResourceSendRequest(
     const std::string& devtoolsRequestId,
     HighResTimeStamp start,
@@ -290,7 +271,8 @@ void PerformanceTracer::reportResourceReceiveResponse(
     HighResTimeStamp start,
     int statusCode,
     const Headers& headers,
-    int encodedDataLength) {
+    int encodedDataLength,
+    folly::dynamic timingData) {
   if (!tracingAtomic_) {
     return;
   }
@@ -308,13 +290,16 @@ void PerformanceTracer::reportResourceReceiveResponse(
       .mimeType = jsinspector_modern::mimeTypeFromHeaders(headers),
       .protocol = "h2",
       .statusCode = statusCode,
+      .timing = std::move(timingData),
       .threadId = getCurrentThreadId(),
   });
 }
 
 void PerformanceTracer::reportResourceFinish(
     const std::string& devtoolsRequestId,
-    HighResTimeStamp start) {
+    HighResTimeStamp start,
+    int encodedDataLength,
+    int decodedBodyLength) {
   if (!tracingAtomic_) {
     return;
   }
@@ -327,6 +312,8 @@ void PerformanceTracer::reportResourceFinish(
   enqueueEvent(PerformanceTracerResourceFinish{
       .requestId = devtoolsRequestId,
       .start = start,
+      .encodedDataLength = encodedDataLength,
+      .decodedBodyLength = decodedBodyLength,
       .threadId = getCurrentThreadId(),
   });
 }
@@ -604,21 +591,6 @@ void PerformanceTracer::enqueueTraceEventsFromPerformanceTracerEvent(
                 .args = folly::dynamic::object("data", std::move(data)),
             });
           },
-          [&](PerformanceTracerResourceWillSendRequest&& event) {
-            folly::dynamic data =
-                folly::dynamic::object("requestId", std::move(event.requestId));
-
-            events.emplace_back(TraceEvent{
-                .name = "ResourceWillSendRequest",
-                .cat = "devtools.timeline",
-                .ph = 'I',
-                .ts = event.start,
-                .pid = processId_,
-                .s = 't',
-                .tid = event.threadId,
-                .args = folly::dynamic::object("data", std::move(data)),
-            });
-          },
           [&](PerformanceTracerResourceSendRequest&& event) {
             folly::dynamic data =
                 folly::dynamic::object("initiator", folly::dynamic::object())(
@@ -651,7 +623,7 @@ void PerformanceTracer::enqueueTraceEventsFromPerformanceTracerEvent(
                 "protocol", event.protocol)(
                 "requestId", std::move(event.requestId))(
                 "statusCode", event.statusCode)(
-                "timing", folly::dynamic::object());
+                "timing", std::move(event.timing));
 
             events.emplace_back(TraceEvent{
                 .name = "ResourceReceiveResponse",
@@ -665,7 +637,9 @@ void PerformanceTracer::enqueueTraceEventsFromPerformanceTracerEvent(
             });
           },
           [&](PerformanceTracerResourceFinish&& event) {
-            folly::dynamic data = folly::dynamic::object("didFail", false)(
+            folly::dynamic data = folly::dynamic::object(
+                "decodedBodyLength", event.decodedBodyLength)("didFail", false)(
+                "encodedDataLength", event.encodedDataLength)(
                 "requestId", std::move(event.requestId));
 
             events.emplace_back(TraceEvent{

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

@@ -148,7 +148,8 @@ class PerformanceTracer {
       HighResTimeStamp start,
       int statusCode,
       const Headers& headers,
-      int encodedDataLength);
+      int encodedDataLength,
+      folly::dynamic timingData);
 
   /**
    * Record a "ResourceFinish" event. Paired with other "Resource*" events,
@@ -158,7 +159,9 @@ class PerformanceTracer {
    */
   void reportResourceFinish(
       const std::string& devtoolsRequestId,
-      HighResTimeStamp start);
+      HighResTimeStamp start,
+      int encodedDataLength,
+      int decodedBodyLength);
 
   /**
    * Creates "Profile" Trace Event.
@@ -233,13 +236,6 @@ class PerformanceTracer {
     HighResTimeStamp createdAt = HighResTimeStamp::now();
   };
 
-  struct PerformanceTracerResourceWillSendRequest {
-    std::string requestId;
-    HighResTimeStamp start;
-    ThreadId threadId;
-    HighResTimeStamp createdAt = HighResTimeStamp::now();
-  };
-
   struct PerformanceTracerResourceSendRequest {
     std::string requestId;
     std::string url;
@@ -253,6 +249,8 @@ class PerformanceTracer {
   struct PerformanceTracerResourceFinish {
     std::string requestId;
     HighResTimeStamp start;
+    int encodedDataLength;
+    int decodedBodyLength;
     ThreadId threadId;
     HighResTimeStamp createdAt = HighResTimeStamp::now();
   };
@@ -265,6 +263,7 @@ class PerformanceTracer {
     std::string mimeType;
     std::string protocol;
     int statusCode;
+    folly::dynamic timing;
     ThreadId threadId;
     HighResTimeStamp createdAt = HighResTimeStamp::now();
   };
@@ -275,7 +274,6 @@ class PerformanceTracer {
       PerformanceTracerEventEventLoopMicrotask,
       PerformanceTracerEventMark,
       PerformanceTracerEventMeasure,
-      PerformanceTracerResourceWillSendRequest,
       PerformanceTracerResourceSendRequest,
       PerformanceTracerResourceReceiveResponse,
       PerformanceTracerResourceFinish>;

packages/react-native/ReactCommon/react/networking/NetworkReporter.cpp

@@ -38,18 +38,16 @@ void NetworkReporter::reportRequestStart(
     const std::optional<ResponseInfo>& redirectResponse) {
   auto now = HighResTimeStamp::now();
 
-  if (ReactNativeFeatureFlags::enableResourceTimingAPI()) {
-    // All builds: Annotate PerformanceResourceTiming metadata
-    {
-      std::lock_guard<std::mutex> lock(perfTimingsMutex_);
-      perfTimingsBuffer_.emplace(
-          requestId,
-          ResourceTimingData{
-              .url = requestInfo.url,
-              .fetchStart = now,
-              .requestStart = now,
-          });
-    }
+  // All builds: Annotate PerformanceResourceTiming metadata
+  {
+    std::lock_guard<std::mutex> lock(perfTimingsMutex_);
+    perfTimingsBuffer_.emplace(
+        requestId,
+        ResourceTimingData{
+            .url = requestInfo.url,
+            .fetchStart = now,
+            .requestStart = now,
+        });
   }
 
 #ifdef REACT_NATIVE_DEBUGGER_ENABLED
@@ -76,7 +74,6 @@ void NetworkReporter::reportRequestStart(
   // Debugger enabled: Add trace events to Performance timeline
   auto& performanceTracer =
       jsinspector_modern::tracing::PerformanceTracer::getInstance();
-  performanceTracer.reportResourceWillSendRequest(requestId, now);
   performanceTracer.reportResourceSendRequest(
       requestId, now, requestInfo.url, requestInfo.httpMethod, headers);
 #endif
@@ -87,14 +84,12 @@ void NetworkReporter::reportConnectionTiming(
     const std::optional<Headers>& headers) {
   auto now = HighResTimeStamp::now();
 
-  if (ReactNativeFeatureFlags::enableResourceTimingAPI()) {
-    // All builds: Annotate PerformanceResourceTiming metadata
-    {
-      std::lock_guard<std::mutex> lock(perfTimingsMutex_);
-      auto it = perfTimingsBuffer_.find(requestId);
-      if (it != perfTimingsBuffer_.end()) {
-        it->second.connectStart = now;
-      }
+  // All builds: Annotate PerformanceResourceTiming metadata
+  {
+    std::lock_guard<std::mutex> lock(perfTimingsMutex_);
+    auto it = perfTimingsBuffer_.find(requestId);
+    if (it != perfTimingsBuffer_.end()) {
+      it->second.connectStart = now;
     }
   }
 
@@ -112,20 +107,18 @@ void NetworkReporter::reportResponseStart(
   auto now = HighResTimeStamp::now();
   auto headers = responseInfo.headers.value_or(Headers{});
 
-  if (ReactNativeFeatureFlags::enableResourceTimingAPI()) {
-    // All builds: Annotate PerformanceResourceTiming metadata
-    {
-      std::lock_guard<std::mutex> lock(perfTimingsMutex_);
-      auto it = perfTimingsBuffer_.find(requestId);
-      if (it != perfTimingsBuffer_.end()) {
-        auto contentType = jsinspector_modern::mimeTypeFromHeaders(headers);
-        it->second.connectEnd = now;
-        it->second.responseStart = now;
-        it->second.responseStatus = responseInfo.statusCode;
-        it->second.contentType = contentType;
-        it->second.encodedBodySize = encodedDataLength;
-        it->second.decodedBodySize = encodedDataLength;
-      }
+  // All builds: Annotate PerformanceResourceTiming metadata
+  {
+    std::lock_guard<std::mutex> lock(perfTimingsMutex_);
+    auto it = perfTimingsBuffer_.find(requestId);
+    if (it != perfTimingsBuffer_.end()) {
+      auto contentType = jsinspector_modern::mimeTypeFromHeaders(headers);
+      it->second.connectEnd = now;
+      it->second.responseStart = now;
+      it->second.responseStatus = responseInfo.statusCode;
+      it->second.contentType = contentType;
+      it->second.encodedBodySize = encodedDataLength;
+      it->second.decodedBodySize = encodedDataLength;
     }
   }
 
@@ -140,9 +133,34 @@ void NetworkReporter::reportResponseStart(
           encodedDataLength));
 
   // Debugger enabled: Add trace event to Performance timeline
-  jsinspector_modern::tracing::PerformanceTracer::getInstance()
-      .reportResourceReceiveResponse(
-          requestId, now, responseInfo.statusCode, headers, encodedDataLength);
+  {
+    folly::dynamic timingData = folly::dynamic::object();
+
+    std::lock_guard<std::mutex> lock(perfTimingsMutex_);
+    auto it = perfTimingsBuffer_.find(requestId);
+    if (it != perfTimingsBuffer_.end()) {
+      // TODO(T238364329): All relative values in timingData should be based on
+      // fetchStart, once implemented.
+      auto requestStart = it->second.requestStart;
+      timingData["requestTime"] = requestStart.toDOMHighResTimeStamp() / 1000;
+      timingData["sendStart"] = 0;
+      timingData["sendEnd"] =
+          (*it->second.connectStart - requestStart).toDOMHighResTimeStamp();
+      timingData["receiveHeadersStart"] =
+          (*it->second.connectStart - requestStart).toDOMHighResTimeStamp();
+      timingData["receiveHeadersEnd"] =
+          (now - requestStart).toDOMHighResTimeStamp();
+    }
+
+    jsinspector_modern::tracing::PerformanceTracer::getInstance()
+        .reportResourceReceiveResponse(
+            requestId,
+            now,
+            responseInfo.statusCode,
+            headers,
+            encodedDataLength,
+            std::move(timingData));
+  }
 #endif
 }
 
@@ -192,8 +210,20 @@ void NetworkReporter::reportResponseEnd(
       requestId, encodedDataLength);
 
   // Debugger enabled: Add trace event to Performance timeline
-  jsinspector_modern::tracing::PerformanceTracer::getInstance()
-      .reportResourceFinish(requestId, now);
+  {
+    int decodedBodyLength = 0;
+
+    std::lock_guard<std::mutex> lock(perfTimingsMutex_);
+    auto it = perfTimingsBuffer_.find(requestId);
+    if (it != perfTimingsBuffer_.end() &&
+        it->second.contentType.starts_with("image/")) {
+      decodedBodyLength = it->second.decodedBodySize;
+    }
+
+    jsinspector_modern::tracing::PerformanceTracer::getInstance()
+        .reportResourceFinish(
+            requestId, now, encodedDataLength, decodedBodyLength);
+  }
 #endif
 }