Bug 1518044 - Move CONTENT_FRAME_TIME calculation code into CompositorBridgeParent. r=jrmuizel

This shouldn't change any behaviour, just puts the code into a separate function so that it's easier to follow.

Differential Revision: https://phabricator.services.mozilla.com/D15794

--HG--
extra : moz-landing-system : lando

gfx/layers/ipc/CompositorBridgeParent.cpp

@@ -115,6 +115,8 @@ using namespace std;
 using base::ProcessId;
 using base::Thread;
 
+using mozilla::Telemetry::LABELS_CONTENT_FRAME_TIME_REASON;
+
 /// Equivalent to asserting CompositorThreadHolder::IsInCompositorThread with
 /// the addition that it doesn't assert if the compositor thread holder is
 /// already gone during late shutdown.
@@ -2412,5 +2414,116 @@ mozilla::ipc::IPCResult CompositorBridgeParent::RecvAllPluginsCaptured() {
 #endif
 }
 
+int32_t RecordContentFrameTime(
+    const VsyncId& aTxnId, const TimeStamp& aVsyncStart,
+    const TimeStamp& aTxnStart, const VsyncId& aCompositeId,
+    const TimeStamp& aCompositeEnd, const TimeDuration& aFullPaintTime,
+    const TimeDuration& aVsyncRate, bool aContainsSVGGroup,
+    bool aRecordUploadStats, wr::RendererStats* aStats /* = nullptr */) {
+  double latencyMs = (aCompositeEnd - aTxnStart).ToMilliseconds();
+  double latencyNorm = latencyMs / aVsyncRate.ToMilliseconds();
+  int32_t fracLatencyNorm = lround(latencyNorm * 100.0);
+  int32_t result = fracLatencyNorm;
+
+#ifdef MOZ_GECKO_PROFILER
+  if (profiler_is_active()) {
+    class ContentFramePayload : public ProfilerMarkerPayload {
+     public:
+      ContentFramePayload(const mozilla::TimeStamp& aStartTime,
+                          const mozilla::TimeStamp& aEndTime)
+          : ProfilerMarkerPayload(aStartTime, aEndTime) {}
+      virtual void StreamPayload(SpliceableJSONWriter& aWriter,
+                                 const TimeStamp& aProcessStartTime,
+                                 UniqueStacks& aUniqueStacks) override {
+        StreamCommonProps("CONTENT_FRAME_TIME", aWriter, aProcessStartTime,
+                          aUniqueStacks);
+      }
+    };
+    profiler_add_marker_for_thread(
+        profiler_current_thread_id(), "CONTENT_FRAME_TIME",
+        MakeUnique<ContentFramePayload>(aTxnStart, aCompositeEnd));
+  }
+#endif
+
+  Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME, fracLatencyNorm);
+  if (aContainsSVGGroup) {
+    Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_WITH_SVG,
+                          fracLatencyNorm);
+  }
+
+  if (aRecordUploadStats) {
+    if (aStats) {
+      latencyMs -= (double(aStats->resource_upload_time) / 1000000.0);
+      latencyNorm = latencyMs / aVsyncRate.ToMilliseconds();
+      fracLatencyNorm = lround(latencyNorm * 100.0);
+    }
+    Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_WITHOUT_RESOURCE_UPLOAD,
+                          fracLatencyNorm);
+
+    if (aStats) {
+      latencyMs -= (double(aStats->gpu_cache_upload_time) / 1000000.0);
+      latencyNorm = latencyMs / aVsyncRate.ToMilliseconds();
+      fracLatencyNorm = lround(latencyNorm * 100.0);
+    }
+    Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_WITHOUT_UPLOAD,
+                          fracLatencyNorm);
+  }
+
+  if (!(aTxnId == VsyncId()) && aVsyncStart) {
+    latencyMs = (aCompositeEnd - aVsyncStart).ToMilliseconds();
+    latencyNorm = latencyMs / aVsyncRate.ToMilliseconds();
+    fracLatencyNorm = lround(latencyNorm * 100.0);
+    Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_VSYNC, fracLatencyNorm);
+
+    // Record CONTENT_FRAME_TIME_REASON.
+    //
+    // Also of note is that when the root WebRenderBridgeParent decides to
+    // skip a composite (due to the Renderer being busy), that won't notify
+    // child WebRenderBridgeParents. That failure will show up as the
+    // composite starting late (since it did), but it's really a fault of a
+    // slow composite on the previous frame, not a slow
+    // CONTENT_FULL_PAINT_TIME. It would be nice to have a separate bucket for
+    // this category (scene was ready on the next vsync, but we chose not to
+    // composite), but I can't find a way to locate the right child
+    // WebRenderBridgeParents from the root. WebRender notifies us of the
+    // child pipelines contained within a render, after it finishes, but I
+    // can't see how to query what child pipeline would have been rendered,
+    // when we choose to not do it.
+    if (fracLatencyNorm < 200) {
+      // Success
+      Telemetry::AccumulateCategorical(
+          LABELS_CONTENT_FRAME_TIME_REASON::OnTime);
+    } else {
+      if (aCompositeId == VsyncId() || aTxnId >= aCompositeId) {
+        // Vsync ids are nonsensical, possibly something got trigged from
+        // outside vsync?
+        Telemetry::AccumulateCategorical(
+            LABELS_CONTENT_FRAME_TIME_REASON::NoVsync);
+      } else if (aCompositeId - aTxnId > 1) {
+        // Composite started late (and maybe took too long as well)
+        if (aFullPaintTime >= TimeDuration::FromMilliseconds(20)) {
+          Telemetry::AccumulateCategorical(
+              LABELS_CONTENT_FRAME_TIME_REASON::MissedCompositeLong);
+        } else if (aFullPaintTime >= TimeDuration::FromMilliseconds(10)) {
+          Telemetry::AccumulateCategorical(
+              LABELS_CONTENT_FRAME_TIME_REASON::MissedCompositeMid);
+        } else if (aFullPaintTime >= TimeDuration::FromMilliseconds(5)) {
+          Telemetry::AccumulateCategorical(
+              LABELS_CONTENT_FRAME_TIME_REASON::MissedCompositeLow);
+        } else {
+          Telemetry::AccumulateCategorical(
+              LABELS_CONTENT_FRAME_TIME_REASON::MissedComposite);
+        }
+      } else {
+        // Composite started on time, but must have taken too long.
+        Telemetry::AccumulateCategorical(
+            LABELS_CONTENT_FRAME_TIME_REASON::SlowComposite);
+      }
+    }
+  }
+
+  return result;
+}
+
 }  // namespace layers
 }  // namespace mozilla

gfx/layers/ipc/CompositorBridgeParent.h

@@ -704,6 +704,13 @@ class CompositorBridgeParent final : public CompositorBridgeParentBase,
   DISALLOW_EVIL_CONSTRUCTORS(CompositorBridgeParent);
 };
 
+int32_t RecordContentFrameTime(
+    const VsyncId& aTxnId, const TimeStamp& aVsyncStart,
+    const TimeStamp& aTxnStart, const VsyncId& aCompositeId,
+    const TimeStamp& aCompositeEnd, const TimeDuration& aFullPaintTime,
+    const TimeDuration& aVsyncRate, bool aContainsSVGGroup,
+    bool aRecordUploadStats, wr::RendererStats* aStats = nullptr);
+
 }  // namespace layers
 }  // namespace mozilla
 

gfx/layers/wr/WebRenderBridgeParent.cpp

@@ -40,8 +40,6 @@
 #include "dwrite.h"
 #endif
 
-using mozilla::Telemetry::LABELS_CONTENT_FRAME_TIME_REASON;
-
 #ifdef MOZ_GECKO_PROFILER
 #include "ProfilerMarkerPayload.h"
 #endif
@@ -1916,129 +1914,28 @@ TransactionId WebRenderBridgeParent::FlushTransactionIdsForEpoch(
 
     if (!IsRootWebRenderBridgeParent() && !mVsyncRate.IsZero() &&
         transactionId.mUseForTelemetry) {
-      double latencyMs =
-          (aEndTime - transactionId.mTxnStartTime).ToMilliseconds();
-      double latencyNorm = latencyMs / mVsyncRate.ToMilliseconds();
-      int32_t fracLatencyNorm = lround(latencyNorm * 100.0);
+      auto fullPaintTime =
+          transactionId.mSceneBuiltTime
+              ? transactionId.mSceneBuiltTime - transactionId.mTxnStartTime
+              : TimeDuration::FromMilliseconds(0);
 
-#ifdef MOZ_GECKO_PROFILER
-      if (profiler_is_active()) {
-        class ContentFramePayload : public ProfilerMarkerPayload {
-         public:
-          ContentFramePayload(const mozilla::TimeStamp& aStartTime,
-                              const mozilla::TimeStamp& aEndTime)
-              : ProfilerMarkerPayload(aStartTime, aEndTime) {}
-          virtual void StreamPayload(SpliceableJSONWriter& aWriter,
-                                     const TimeStamp& aProcessStartTime,
-                                     UniqueStacks& aUniqueStacks) override {
-            StreamCommonProps("CONTENT_FRAME_TIME", aWriter, aProcessStartTime,
-                              aUniqueStacks);
-          }
-        };
-        profiler_add_marker_for_thread(
-            profiler_current_thread_id(), "CONTENT_FRAME_TIME",
-            MakeUnique<ContentFramePayload>(transactionId.mTxnStartTime,
-                                            aEndTime));
-      }
-#endif
-
-      if (fracLatencyNorm > 200) {
+      int32_t contentFrameTime = RecordContentFrameTime(
+          transactionId.mVsyncId, transactionId.mVsyncStartTime,
+          transactionId.mTxnStartTime, aCompositeStartId, aEndTime,
+          fullPaintTime, mVsyncRate, transactionId.mContainsSVGGroup, true,
+          aStats);
+      if (contentFrameTime > 200) {
         aOutputStats->AppendElement(FrameStats(
             transactionId.mId, aCompositeStartTime, aRenderStartTime, aEndTime,
-            fracLatencyNorm,
+            contentFrameTime,
             aStats ? (double(aStats->resource_upload_time) / 1000000.0) : 0.0,
             aStats ? (double(aStats->gpu_cache_upload_time) / 1000000.0) : 0.0,
             transactionId.mTxnStartTime, transactionId.mRefreshStartTime,
             transactionId.mFwdTime, transactionId.mSceneBuiltTime,
             transactionId.mSkippedComposites, transactionId.mTxnURL));
-      }
 
-      Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME, fracLatencyNorm);
-      if (fracLatencyNorm > 200) {
         wr::RenderThread::Get()->NotifySlowFrame(mApi->GetId());
       }
-      if (transactionId.mContainsSVGGroup) {
-        Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_WITH_SVG,
-                              fracLatencyNorm);
-      }
-
-      if (aStats) {
-        latencyMs -= (double(aStats->resource_upload_time) / 1000000.0);
-        latencyNorm = latencyMs / mVsyncRate.ToMilliseconds();
-        fracLatencyNorm = lround(latencyNorm * 100.0);
-      }
-      Telemetry::Accumulate(
-          Telemetry::CONTENT_FRAME_TIME_WITHOUT_RESOURCE_UPLOAD,
-          fracLatencyNorm);
-
-      if (aStats) {
-        latencyMs -= (double(aStats->gpu_cache_upload_time) / 1000000.0);
-        latencyNorm = latencyMs / mVsyncRate.ToMilliseconds();
-        fracLatencyNorm = lround(latencyNorm * 100.0);
-      }
-      Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_WITHOUT_UPLOAD,
-                            fracLatencyNorm);
-
-      if (!(transactionId.mVsyncId == VsyncId()) &&
-          transactionId.mVsyncStartTime) {
-        latencyMs = (aEndTime - transactionId.mVsyncStartTime).ToMilliseconds();
-        latencyNorm = latencyMs / mVsyncRate.ToMilliseconds();
-        fracLatencyNorm = lround(latencyNorm * 100.0);
-        Telemetry::Accumulate(Telemetry::CONTENT_FRAME_TIME_VSYNC,
-                              fracLatencyNorm);
-
-        // Record CONTENT_FRAME_TIME_REASON.
-        //
-        // Also of note is that when the root WebRenderBridgeParent decides to
-        // skip a composite (due to the Renderer being busy), that won't notify
-        // child WebRenderBridgeParents. That failure will show up as the
-        // composite starting late (since it did), but it's really a fault of a
-        // slow composite on the previous frame, not a slow
-        // CONTENT_FULL_PAINT_TIME. It would be nice to have a separate bucket for
-        // this category (scene was ready on the next vsync, but we chose not to
-        // composite), but I can't find a way to locate the right child
-        // WebRenderBridgeParents from the root. WebRender notifies us of the
-        // child pipelines contained within a render, after it finishes, but I
-        // can't see how to query what child pipeline would have been rendered,
-        // when we choose to not do it.
-        if (fracLatencyNorm < 200) {
-          // Success
-          Telemetry::AccumulateCategorical(
-              LABELS_CONTENT_FRAME_TIME_REASON::OnTime);
-        } else {
-          if (transactionId.mVsyncId == VsyncId() ||
-              aCompositeStartId == VsyncId() ||
-              transactionId.mVsyncId >= aCompositeStartId) {
-            // Vsync ids are nonsensical, possibly something got trigged from
-            // outside vsync?
-            Telemetry::AccumulateCategorical(
-                LABELS_CONTENT_FRAME_TIME_REASON::NoVsync);
-          } else if (aCompositeStartId - transactionId.mVsyncId > 1) {
-            auto fullPaintTime =
-                transactionId.mSceneBuiltTime
-                    ? transactionId.mSceneBuiltTime - transactionId.mTxnStartTime
-                    : TimeDuration::FromMilliseconds(0);
-            // Composite started late (and maybe took too long as well)
-            if (fullPaintTime >= TimeDuration::FromMilliseconds(20)) {
-              Telemetry::AccumulateCategorical(
-                  LABELS_CONTENT_FRAME_TIME_REASON::MissedCompositeLong);
-            } else if (fullPaintTime >= TimeDuration::FromMilliseconds(10)) {
-              Telemetry::AccumulateCategorical(
-                  LABELS_CONTENT_FRAME_TIME_REASON::MissedCompositeMid);
-            } else if (fullPaintTime >= TimeDuration::FromMilliseconds(5)) {
-              Telemetry::AccumulateCategorical(
-                  LABELS_CONTENT_FRAME_TIME_REASON::MissedCompositeLow);
-            } else {
-              Telemetry::AccumulateCategorical(
-                  LABELS_CONTENT_FRAME_TIME_REASON::MissedComposite);
-            }
-          } else {
-            // Composite start on time, but must have taken too long.
-            Telemetry::AccumulateCategorical(
-                LABELS_CONTENT_FRAME_TIME_REASON::SlowComposite);
-          }
-        }
-      }
     }
 
 #if defined(ENABLE_FRAME_LATENCY_LOG)