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 446688 939a5605cccfb28c7f685d29f2b89d6e53bfaddf
parent 446687 5125f9c64d2753e93c29cdd9b958194b0e17db80
child 446689 1abdc7367834b8dfc8e0606bf688f11a901730d3
push id35046
push userbtara@mozilla.com
push dateFri, 16 Nov 2018 09:46:36 +0000
treeherdermozilla-central@02f799e4c3da [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjrmuizel
bugs1503405
milestone65.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
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",