Bug 1503405 - Add telemetry for CONTENT_FRAME_WITH with texture upload excluded. r=jrmuizel
authorMatt Woodrow <mwoodrow@mozilla.com>
Thu, 15 Nov 2018 23:09:05 +0000
changeset 488467 939a5605cccfb28c7f685d29f2b89d6e53bfaddf
parent 488466 5125f9c64d2753e93c29cdd9b958194b0e17db80
child 488468 1abdc7367834b8dfc8e0606bf688f11a901730d3
push id127
push usermtabara@mozilla.com
push dateFri, 16 Nov 2018 17:02:58 +0000
reviewersjrmuizel
bugs1503405
milestone65.0a1
Bug 1503405 - Add telemetry for CONTENT_FRAME_WITH with texture upload excluded. r=jrmuizel Differential Revision: https://phabricator.services.mozilla.com/D11971
gfx/layers/ipc/CompositorBridgeParent.cpp
gfx/layers/ipc/CompositorBridgeParent.h
gfx/layers/wr/WebRenderBridgeParent.cpp
gfx/layers/wr/WebRenderBridgeParent.h
gfx/webrender_bindings/RenderThread.cpp
gfx/webrender_bindings/RendererOGL.cpp
gfx/webrender_bindings/RendererOGL.h
gfx/webrender_bindings/src/bindings.rs
gfx/webrender_bindings/webrender_ffi_generated.h
toolkit/components/telemetry/Histograms.json
--- a/gfx/layers/ipc/CompositorBridgeParent.cpp
+++ b/gfx/layers/ipc/CompositorBridgeParent.cpp
@@ -2203,17 +2203,18 @@ CompositorBridgeParent::DidComposite(Tim
     mPendingTransaction = TransactionId{0};
   }
 }
 
 void
 CompositorBridgeParent::NotifyPipelineRendered(const wr::PipelineId& aPipelineId,
                                                const wr::Epoch& aEpoch,
                                                TimeStamp& aCompositeStart,
-                                               TimeStamp& aCompositeEnd)
+                                               TimeStamp& aCompositeEnd,
+                                               wr::RendererStats* aStats)
 {
   if (!mWrBridge) {
     return;
   }
 
   RefPtr<UiCompositorControllerParent> uiController =
     UiCompositorControllerParent::GetFromRootLayerTreeId(mRootLayerTreeID);
 
@@ -2238,17 +2239,17 @@ CompositorBridgeParent::NotifyPipelineRe
     if (lts->mCrossProcessParent &&
         lts->mWrBridge &&
         lts->mWrBridge->PipelineId() == aPipelineId) {
 
       lts->mWrBridge->RemoveEpochDataPriorTo(aEpoch);
 
       if (!mPaused) {
         CrossProcessCompositorBridgeParent* cpcp = lts->mCrossProcessParent;
-        TransactionId transactionId = lts->mWrBridge->FlushTransactionIdsForEpoch(aEpoch, aCompositeEnd, uiController);
+        TransactionId transactionId = lts->mWrBridge->FlushTransactionIdsForEpoch(aEpoch, aCompositeEnd, uiController, aStats);
         Unused << cpcp->SendDidComposite(aLayersId, transactionId, aCompositeStart, aCompositeEnd);
       }
     }
   });
 }
 
 RefPtr<AsyncImagePipelineManager>
 CompositorBridgeParent::GetAsyncImagePipelineManager() const
--- a/gfx/layers/ipc/CompositorBridgeParent.h
+++ b/gfx/layers/ipc/CompositorBridgeParent.h
@@ -279,17 +279,18 @@ public:
 
   bool IsSameProcess() const override;
 
   void NotifyWebRenderError(wr::WebRenderError aError);
   void NotifyWebRenderContextPurge();
   void NotifyPipelineRendered(const wr::PipelineId& aPipelineId,
                               const wr::Epoch& aEpoch,
                               TimeStamp& aCompositeStart,
-                              TimeStamp& aCompositeEnd);
+                              TimeStamp& aCompositeEnd,
+                              wr::RendererStats* aStats = nullptr);
   RefPtr<AsyncImagePipelineManager> GetAsyncImagePipelineManager() const;
 
   PCompositorWidgetParent* AllocPCompositorWidgetParent(const CompositorWidgetInitData& aInitData) override;
   bool DeallocPCompositorWidgetParent(PCompositorWidgetParent* aActor) override;
 
   void ObserveLayersUpdate(LayersId aLayersId, LayersObserverEpoch aEpoch, bool aActive) override { }
 
   /**
--- a/gfx/layers/wr/WebRenderBridgeParent.cpp
+++ b/gfx/layers/wr/WebRenderBridgeParent.cpp
@@ -1806,17 +1806,18 @@ WebRenderBridgeParent::LastPendingTransa
   if (!mPendingTransactionIds.empty()) {
     id = mPendingTransactionIds.back().mId;
   }
   return id;
 }
 
 TransactionId
 WebRenderBridgeParent::FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch, const TimeStamp& aEndTime,
-                                                   UiCompositorControllerParent* aUiController)
+                                                   UiCompositorControllerParent* aUiController,
+                                                   wr::RendererStats* aStats)
 {
   TransactionId id{0};
   while (!mPendingTransactionIds.empty()) {
     const auto& transactionId = mPendingTransactionIds.front();
 
     if (aEpoch.mHandle < transactionId.mEpoch.mHandle) {
       break;
     }
@@ -1844,16 +1845,30 @@ WebRenderBridgeParent::FlushTransactionI
 
       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 defined(ENABLE_FRAME_LATENCY_LOG)
     if (transactionId.mRefreshStartTime) {
       int32_t latencyMs = lround((aEndTime - transactionId.mRefreshStartTime).ToMilliseconds());
       printf_stderr("From transaction start to end of generate frame latencyMs %d this %p\n", latencyMs, this);
     }
     if (transactionId.mFwdTime) {
--- a/gfx/layers/wr/WebRenderBridgeParent.h
+++ b/gfx/layers/wr/WebRenderBridgeParent.h
@@ -164,17 +164,18 @@ public:
                                 bool aContainsSVGGroup,
                                 const TimeStamp& aRefreshStartTime,
                                 const TimeStamp& aTxnStartTime,
                                 const TimeStamp& aFwdTime,
                                 const bool aIsFirstPaint,
                                 const bool aUseForTelemetry = true);
   TransactionId LastPendingTransactionId();
   TransactionId FlushTransactionIdsForEpoch(const wr::Epoch& aEpoch, const TimeStamp& aEndTime,
-                                            UiCompositorControllerParent* aUiController);
+                                            UiCompositorControllerParent* aUiController,
+                                            wr::RendererStats* aStats = nullptr);
 
   TextureFactoryIdentifier GetTextureFactoryIdentifier();
 
   void ExtractImageCompositeNotifications(nsTArray<ImageCompositeNotificationInfo>* aNotifications);
 
   wr::Epoch GetCurrentEpoch() const { return mWrEpoch; }
   wr::IdNamespace GetIdNamespace()
   {
--- a/gfx/webrender_bindings/RenderThread.cpp
+++ b/gfx/webrender_bindings/RenderThread.cpp
@@ -339,33 +339,35 @@ RenderThread::RunEvent(wr::WindowId aWin
   aEvent = nullptr;
 }
 
 static void
 NotifyDidRender(layers::CompositorBridgeParent* aBridge,
                 RefPtr<WebRenderPipelineInfo> aInfo,
                 TimeStamp aStart,
                 TimeStamp aEnd,
-                bool aRender)
+                bool aRender,
+                RendererStats aStats)
 {
   if (aRender && aBridge->GetWrBridge()) {
     // We call this here to mimic the behavior in LayerManagerComposite, as to
     // not change what Talos measures. That is, we do not record an empty frame
     // as a frame.
     aBridge->GetWrBridge()->RecordFrame();
   }
 
   auto info = aInfo->Raw();
 
   for (uintptr_t i = 0; i < info.epochs.length; i++) {
     aBridge->NotifyPipelineRendered(
         info.epochs.data[i].pipeline_id,
         info.epochs.data[i].epoch,
         aStart,
-        aEnd);
+        aEnd,
+        &aStats);
   }
 }
 
 void
 RenderThread::UpdateAndRender(wr::WindowId aWindowId,
                               const TimeStamp& aStartTime,
                               bool aRender,
                               const Maybe<gfx::IntSize>& aReadbackSize,
@@ -379,34 +381,36 @@ RenderThread::UpdateAndRender(wr::Window
   auto it = mRenderers.find(aWindowId);
   MOZ_ASSERT(it != mRenderers.end());
   if (it == mRenderers.end()) {
     return;
   }
 
   auto& renderer = it->second;
   bool rendered = false;
+  RendererStats stats = { 0 };
   if (aRender) {
-    rendered = renderer->UpdateAndRender(aReadbackSize, aReadbackBuffer, aHadSlowFrame);
+    rendered = renderer->UpdateAndRender(aReadbackSize, aReadbackBuffer, aHadSlowFrame, &stats);
   } else {
     renderer->Update();
   }
   // Check graphics reset status even when rendering is skipped.
   renderer->CheckGraphicsResetStatus();
 
   TimeStamp end = TimeStamp::Now();
   auto info = renderer->FlushPipelineInfo();
 
   layers::CompositorThreadHolder::Loop()->PostTask(NewRunnableFunction(
     "NotifyDidRenderRunnable",
     &NotifyDidRender,
     renderer->GetCompositorBridge(),
     info,
     aStartTime, end,
-    aRender
+    aRender,
+    stats
   ));
 
   if (rendered) {
     // Wait for GPU after posting NotifyDidRender, since the wait is not
     // necessary for the NotifyDidRender.
     // The wait is necessary for Textures recycling of AsyncImagePipelineManager
     // and for avoiding GPU queue is filled with too much tasks.
     // WaitForGPU's implementation is different for each platform.
--- a/gfx/webrender_bindings/RendererOGL.cpp
+++ b/gfx/webrender_bindings/RendererOGL.cpp
@@ -102,17 +102,20 @@ RendererOGL::Update()
 
 static void
 DoNotifyWebRenderContextPurge(layers::CompositorBridgeParent* aBridge)
 {
   aBridge->NotifyWebRenderContextPurge();
 }
 
 bool
-RendererOGL::UpdateAndRender(const Maybe<gfx::IntSize>& aReadbackSize, const Maybe<Range<uint8_t>>& aReadbackBuffer, bool aHadSlowFrame)
+RendererOGL::UpdateAndRender(const Maybe<gfx::IntSize>& aReadbackSize,
+                             const Maybe<Range<uint8_t>>& aReadbackBuffer,
+                             bool aHadSlowFrame,
+                             RendererStats* aOutStats)
 {
   uint32_t flags = gfx::gfxVars::WebRenderDebugFlags();
   // Disable debug flags during readback
   if (aReadbackBuffer.isSome()) {
     flags = 0;
   }
 
   if (mDebugFlags.mBits != flags) {
@@ -139,17 +142,17 @@ RendererOGL::UpdateAndRender(const Maybe
   if (!mCompositor->BeginFrame()) {
     return false;
   }
 
   wr_renderer_update(mRenderer);
 
   auto size = mCompositor->GetBufferSize();
 
-  if (!wr_renderer_render(mRenderer, size.width, size.height, aHadSlowFrame)) {
+  if (!wr_renderer_render(mRenderer, size.width, size.height, aHadSlowFrame, aOutStats)) {
     NotifyWebRenderError(WebRenderError::RENDER);
   }
 
   if (aReadbackBuffer.isSome()) {
     MOZ_ASSERT(aReadbackSize.isSome());
     wr_renderer_readback(mRenderer,
                          aReadbackSize.ref().width, aReadbackSize.ref().height,
                          &aReadbackBuffer.ref()[0],
--- a/gfx/webrender_bindings/RendererOGL.h
+++ b/gfx/webrender_bindings/RendererOGL.h
@@ -52,17 +52,20 @@ class RendererOGL
 
 public:
   wr::WrExternalImageHandler GetExternalImageHandler();
 
   /// This can be called on the render thread only.
   void Update();
 
   /// This can be called on the render thread only.
-  bool UpdateAndRender(const Maybe<gfx::IntSize>& aReadbackSize, const Maybe<Range<uint8_t>>& aReadbackBuffer, bool aHadSlowFrame);
+  bool UpdateAndRender(const Maybe<gfx::IntSize>& aReadbackSize,
+                       const Maybe<Range<uint8_t>>& aReadbackBuffer,
+                       bool aHadSlowFrame,
+                       RendererStats* aOutStats);
 
   /// This can be called on the render thread only.
   void WaitForGPU();
 
   /// This can be called on the render thread only.
   void SetProfilerEnabled(bool aEnabled);
 
   /// This can be called on the render thread only.
--- a/gfx/webrender_bindings/src/bindings.rs
+++ b/gfx/webrender_bindings/src/bindings.rs
@@ -8,17 +8,17 @@ use std::sync::Arc;
 use std::sync::atomic::{AtomicUsize, Ordering};
 use std::ops::Range;
 use std::os::raw::{c_void, c_char, c_float};
 #[cfg(target_os = "android")]
 use std::os::raw::{c_int};
 use gleam::gl;
 
 use webrender::api::*;
-use webrender::{ReadPixelsFormat, Renderer, RendererOptions, ThreadListener};
+use webrender::{ReadPixelsFormat, Renderer, RendererOptions, RendererStats, ThreadListener};
 use webrender::{ExternalImage, ExternalImageHandler, ExternalImageSource};
 use webrender::DebugFlags;
 use webrender::{ApiRecordingReceiver, BinaryRecorder};
 use webrender::{AsyncPropertySampler, PipelineInfo, SceneBuilderHooks};
 use webrender::{UploadMethod, VertexUsageHint};
 use webrender::{Device, Shaders, WrShaders, ShaderPrecacheFlags};
 use thread_profiler::register_thread_with_profiler;
 use moz2d_renderer::Moz2dBlobImageHandler;
@@ -604,22 +604,26 @@ pub extern "C" fn wr_renderer_set_extern
 pub extern "C" fn wr_renderer_update(renderer: &mut Renderer) {
     renderer.update();
 }
 
 #[no_mangle]
 pub extern "C" fn wr_renderer_render(renderer: &mut Renderer,
                                      width: u32,
                                      height: u32,
-                                     had_slow_frame: bool) -> bool {
+                                     had_slow_frame: bool,
+                                     out_stats: &mut RendererStats) -> bool {
     if had_slow_frame {
       renderer.notify_slow_frame();
     }
     match renderer.render(DeviceUintSize::new(width, height)) {
-        Ok(_) => true,
+        Ok(stats) => {
+            *out_stats = stats;
+            true
+        }
         Err(errors) => {
             for e in errors {
                 warn!(" Failed to render: {:?}", e);
                 let msg = CString::new(format!("wr_renderer_render: {:?}", e)).unwrap();
                 unsafe {
                     gfx_critical_note(msg.as_ptr());
                 }
             }
--- a/gfx/webrender_bindings/webrender_ffi_generated.h
+++ b/gfx/webrender_bindings/webrender_ffi_generated.h
@@ -996,16 +996,34 @@ struct MutByteSlice {
 struct WrDebugFlags {
   uint32_t mBits;
 
   bool operator==(const WrDebugFlags& aOther) const {
     return mBits == aOther.mBits;
   }
 };
 
+struct RendererStats {
+  uintptr_t total_draw_calls;
+  uintptr_t alpha_target_count;
+  uintptr_t color_target_count;
+  uintptr_t texture_upload_kb;
+  uint64_t resource_upload_time;
+  uint64_t gpu_cache_upload_time;
+
+  bool operator==(const RendererStats& aOther) const {
+    return total_draw_calls == aOther.total_draw_calls &&
+           alpha_target_count == aOther.alpha_target_count &&
+           color_target_count == aOther.color_target_count &&
+           texture_upload_kb == aOther.texture_upload_kb &&
+           resource_upload_time == aOther.resource_upload_time &&
+           gpu_cache_upload_time == aOther.gpu_cache_upload_time;
+  }
+};
+
 struct WrExternalImage {
   WrExternalImageType image_type;
   uint32_t handle;
   float u0;
   float v0;
   float u1;
   float v1;
   const uint8_t *buff;
@@ -1129,18 +1147,22 @@ extern void apz_register_sampler(WrWindo
 
 extern void apz_register_updater(WrWindowId aWindowId);
 
 extern void apz_run_updater(WrWindowId aWindowId);
 
 extern void apz_sample_transforms(WrWindowId aWindowId,
                                   Transaction *aTransaction);
 
+extern void gecko_profiler_end_marker(const char *aName);
+
 extern void gecko_profiler_register_thread(const char *aName);
 
+extern void gecko_profiler_start_marker(const char *aName);
+
 extern void gecko_profiler_unregister_thread();
 
 extern void gfx_critical_error(const char *aMsg);
 
 extern void gfx_critical_note(const char *aMsg);
 
 extern bool gfx_use_wrench();
 
@@ -1151,19 +1173,16 @@ extern bool is_glcontext_angle(void *aGl
 extern bool is_glcontext_egl(void *aGlcontextPtr);
 
 extern bool is_in_compositor_thread();
 
 extern bool is_in_main_thread();
 
 extern bool is_in_render_thread();
 
-extern void gecko_profiler_start_marker(const char* name);
-extern void gecko_profiler_end_marker(const char* name);
-
 extern void record_telemetry_time(TelemetryProbe aProbe,
                                   uint64_t aTimeNs);
 
 WR_INLINE
 bool remove_program_binary_disk_cache(const nsAString *aProfPath)
 WR_FUNC;
 
 WR_INLINE
@@ -1642,17 +1661,18 @@ void wr_renderer_readback(Renderer *aRen
                           uint8_t *aDstBuffer,
                           uintptr_t aBufferSize)
 WR_FUNC;
 
 WR_INLINE
 bool wr_renderer_render(Renderer *aRenderer,
                         uint32_t aWidth,
                         uint32_t aHeight,
-                        bool aHadSlowFrame)
+                        bool aHadSlowFrame,
+                        RendererStats *aOutStats)
 WR_FUNC;
 
 WR_INLINE
 void wr_renderer_set_debug_flags(Renderer *aRenderer,
                                  WrDebugFlags aFlags)
 WR_FUNC;
 
 WR_INLINE
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -13069,16 +13069,36 @@
     "alert_emails": ["gfx-telemetry-alerts@mozilla.com", "mwoodrow@mozilla.com"],
     "bug_numbers": [1483549],
     "expires_in_version": "66",
     "kind": "exponential",
     "high": 5000,
     "n_buckets": 50,
     "description": "The time, in percentage of a vsync interval, spent from beginning a paint in the content process until that frame is presented in the compositor, for frames that contained an SVG to be drawn by WebRender"
   },
+  "CONTENT_FRAME_TIME_WITHOUT_RESOURCE_UPLOAD": {
+    "record_in_processes": ["main", "gpu"],
+    "alert_emails": ["gfx-telemetry-alerts@mozilla.com", "mwoodrow@mozilla.com"],
+    "bug_numbers": [1503405],
+    "expires_in_version": "70",
+    "kind": "exponential",
+    "high": 5000,
+    "n_buckets": 50,
+    "description": "The time, in percentage of a vsync interval, spent from beginning a paint in the content process until that frame is presented in the compositor by WebRender, excluding time spent uploading resources"
+  },
+  "CONTENT_FRAME_TIME_WITHOUT_UPLOAD": {
+    "record_in_processes": ["main", "gpu"],
+    "alert_emails": ["gfx-telemetry-alerts@mozilla.com", "mwoodrow@mozilla.com"],
+    "bug_numbers": [1503405],
+    "expires_in_version": "70",
+    "kind": "exponential",
+    "high": 5000,
+    "n_buckets": 50,
+    "description": "The time, in percentage of a vsync interval, spent from beginning a paint in the content process until that frame is presented in the compositor by WebRender, excluding time spent uploading any content"
+  },
   "CONTENT_LARGE_PAINT_PHASE_WEIGHT": {
     "record_in_processes": ["main", "content"],
     "alert_emails": ["gfx-telemetry-alerts@mozilla.com", "mwoodrow@mozilla.com"],
     "bug_numbers": [1309442],
     "expires_in_version": "66",
     "keyed": true,
     "keys": ["dl", "flb", "fr", "r"],
     "kind": "linear",