Bug 1778395 - Part 1: Record time between frame creation and the start of frame building. r=jrmuizel,chutten

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

gfx/metrics.yaml

@@ -154,3 +154,19 @@ wr:
       - gfx-telemetry-alerts@mozilla.com
     expires: never
     telemetry_mirror: WR_TEXTURE_CACHE_UPDATE_TIME
+  time_to_frame_build:
+    type: timing_distribution
+    description: >
+      Time elapsed between the construction of a transaction and the
+      associated frame build beginning.
+    time_unit: microsecond
+    bugs:
+      - https://bugzilla.mozilla.org/show_bug.cgi?id=1778395
+    data_reviews:
+      - https://bugzilla.mozilla.org/show_bug.cgi?id=1778395
+    data_sensitivity:
+      - technical
+    notification_emails:
+      - gfx-telemetry-alerts@mozilla.com
+    expires: never
+    telemetry_mirror: WR_TIME_TO_FRAME_BUILD_MS

gfx/wr/webrender/src/render_api.rs

@@ -170,6 +170,9 @@ pub struct Transaction {
     /// generate_frame().
     generate_frame: GenerateFrame,
 
+    /// Time when this transaction was constructed.
+    creation_time: u64,
+
     /// Set to true in order to force re-rendering even if WebRender can't internally
     /// detect that something has changed.
     pub invalidate_rendered_frame: bool,
@@ -190,6 +193,7 @@ impl Transaction {
             notifications: Vec::new(),
             use_scene_builder_thread: true,
             generate_frame: GenerateFrame::No,
+            creation_time: precise_time_ns(),
             invalidate_rendered_frame: false,
             low_priority: false,
             render_reasons: RenderReasons::empty(),
@@ -404,6 +408,7 @@ impl Transaction {
             notifications: self.notifications,
             use_scene_builder_thread: self.use_scene_builder_thread,
             generate_frame: self.generate_frame,
+            creation_time: Some(self.creation_time),
             invalidate_rendered_frame: self.invalidate_rendered_frame,
             low_priority: self.low_priority,
             blob_rasterizer: None,
@@ -578,6 +583,8 @@ pub struct TransactionMsg {
     pub resource_updates: Vec<ResourceUpdate>,
     /// Whether to trigger frame building and rendering if something has changed.
     pub generate_frame: GenerateFrame,
+    /// Creation time of this transaction.
+    pub creation_time: Option<u64>,
     /// Whether to force frame building and rendering even if no changes are internally
     /// observed.
     pub invalidate_rendered_frame: bool,
@@ -1215,6 +1222,7 @@ impl RenderApi {
             resource_updates: Vec::new(),
             notifications: Vec::new(),
             generate_frame: GenerateFrame::No,
+            creation_time: None,
             invalidate_rendered_frame: false,
             use_scene_builder_thread: false,
             low_priority: false,

gfx/wr/webrender/src/render_backend.rs

@@ -67,6 +67,7 @@ use std::path::PathBuf;
 #[cfg(feature = "replay")]
 use crate::frame_builder::Frame;
 use time::precise_time_ns;
+use core::time::Duration;
 use crate::util::{Recycler, VecHelper, drain_filter};
 
 #[cfg_attr(feature = "capture", derive(Serialize))]
@@ -914,6 +915,7 @@ impl RenderBackend {
                 txn.invalidate_rendered_frame,
                 frame_counter,
                 has_built_scene,
+                None,
             );
         }
 
@@ -1261,7 +1263,8 @@ impl RenderBackend {
                 txn.generate_frame.id(),
                 txn.invalidate_rendered_frame,
                 frame_counter,
-                false
+                false,
+                txn.creation_time,
             );
         }
         if built_frame {
@@ -1299,7 +1302,8 @@ impl RenderBackend {
                     None,
                     false,
                     frame_counter,
-                    false);
+                    false,
+                    None);
             }
             #[cfg(feature = "capture")]
             match built_frame {
@@ -1321,6 +1325,7 @@ impl RenderBackend {
         invalidate_rendered_frame: bool,
         frame_counter: &mut u32,
         has_built_scene: bool,
+        start_time: Option<u64>
     ) -> bool {
         let requested_frame = render_frame;
 
@@ -1391,6 +1396,9 @@ impl RenderBackend {
         }
 
         if build_frame {
+            if start_time.is_some() {
+              Telemetry::record_time_to_frame_build(Duration::from_nanos(precise_time_ns() - start_time.unwrap()));
+            }
             profile_scope!("generate frame");
 
             *frame_counter += 1;

gfx/wr/webrender/src/telemetry.rs

@@ -25,6 +25,7 @@ impl Telemetry {
     pub fn stop_and_accumulate_sceneswap_time(_id: TimerId) { }
     pub fn cancel_sceneswap_time(_id: TimerId) { }
     pub fn record_texture_cache_update_time(_duration: Duration) { }
+    pub fn record_time_to_frame_build(_duration: Duration) { }
 }
 
 #[cfg(feature = "gecko")]
@@ -40,4 +41,5 @@ impl Telemetry {
     pub fn stop_and_accumulate_sceneswap_time(id: TimerId) { wr::sceneswap_time.stop_and_accumulate(id); }
     pub fn cancel_sceneswap_time(id: TimerId) { wr::sceneswap_time.cancel(id); }
     pub fn record_texture_cache_update_time(duration: Duration) { wr::texture_cache_update_time.accumulate_raw_duration(duration); }
+    pub fn record_time_to_frame_build(duration: Duration) { wr::time_to_frame_build.accumulate_raw_duration(duration); }
 }

toolkit/components/telemetry/Histograms.json

@@ -16204,6 +16204,17 @@
     "n_buckets": 50,
     "description": "Time taken by WebRender to update the texture cache in milliseconds."
   },
+  "WR_TIME_TO_FRAME_BUILD_MS": {
+    "record_in_processes": [ "main", "gpu" ],
+    "products": [ "firefox" ],
+    "alert_emails": [ "gfx-telemetry-alerts@mozilla.com" ],
+    "bug_numbers": [ 1778395 ],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 1000,
+    "n_buckets": 50,
+    "description": "Time elapsed (in milliseconds) between the construction of a transaction and the associated frame build beginning."
+  },
   "WEB_AUDIO_BECOMES_AUDIBLE_TIME": {
     "record_in_processes": ["content"],
     "products": ["firefox"],