Implement basic Time To First Paint and First Contentful Paint PWMs

Cargo.lock

@@ -522,6 +522,7 @@ dependencies = [
  "itertools 0.5.10 (registry+https://github.com/rust-lang/crates.io-index)",
  "layout_traits 0.0.1",
  "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)",
+ "metrics 0.0.1",
  "msg 0.0.1",
  "net 0.0.1",
  "net_traits 0.0.1",
@@ -1501,6 +1502,7 @@ dependencies = [
  "layout_traits 0.0.1",
  "lazy_static 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)",
  "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)",
+ "metrics 0.0.1",
  "msg 0.0.1",
  "net_traits 0.0.1",
  "parking_lot 0.4.4 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -1527,6 +1529,7 @@ version = "0.0.1"
 dependencies = [
  "gfx 0.0.1",
  "ipc-channel 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
+ "metrics 0.0.1",
  "msg 0.0.1",
  "net_traits 0.0.1",
  "profile_traits 0.0.1",
@@ -1694,6 +1697,16 @@ dependencies = [
  "toml 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
+[[package]]
+name = "metrics"
+version = "0.0.1"
+dependencies = [
+ "gfx 0.0.1",
+ "profile_traits 0.0.1",
+ "servo_config 0.0.1",
+ "time 0.1.37 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
 [[package]]
 name = "mime"
 version = "0.2.4"
@@ -2453,6 +2466,7 @@ dependencies = [
  "lazy_static 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)",
  "libc 0.2.23 (registry+https://github.com/rust-lang/crates.io-index)",
  "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)",
+ "metrics 0.0.1",
  "mime 0.2.4 (registry+https://github.com/rust-lang/crates.io-index)",
  "mime_guess 1.8.1 (registry+https://github.com/rust-lang/crates.io-index)",
  "msg 0.0.1",
@@ -2512,6 +2526,7 @@ dependencies = [
  "ipc-channel 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "libc 0.2.23 (registry+https://github.com/rust-lang/crates.io-index)",
  "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)",
+ "metrics 0.0.1",
  "msg 0.0.1",
  "net_traits 0.0.1",
  "profile_traits 0.0.1",
@@ -2556,6 +2571,7 @@ dependencies = [
  "hyper_serde 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "ipc-channel 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "libc 0.2.23 (registry+https://github.com/rust-lang/crates.io-index)",
+ "metrics 0.0.1",
  "msg 0.0.1",
  "net_traits 0.0.1",
  "offscreen_gl_context 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)",

components/config/opts.rs

@@ -224,6 +224,9 @@ pub struct Opts {
 
     /// Unminify Javascript.
     pub unminify_js: bool,
+
+    /// Print Progressive Web Metrics to console.
+    pub print_pwm: bool,
 }
 
 fn print_usage(app: &str, opts: &Options) {
@@ -544,6 +547,7 @@ pub fn default_opts() -> Opts {
         signpost: false,
         certificate_path: None,
         unminify_js: false,
+        print_pwm: false,
     }
 }
 
@@ -608,6 +612,7 @@ pub fn from_cmdline_args(args: &[String]) -> ArgumentParsingResult {
     opts.optopt("", "profiler-db-user", "Profiler database user", "");
     opts.optopt("", "profiler-db-pass", "Profiler database password", "");
     opts.optopt("", "profiler-db-name", "Profiler database name", "");
+    opts.optflag("", "print-pwm", "Print Progressive Web Metrics");
 
     let opt_match = match opts.parse(args) {
         Ok(m) => m,
@@ -843,6 +848,7 @@ pub fn from_cmdline_args(args: &[String]) -> ArgumentParsingResult {
         signpost: debug_options.signpost,
         certificate_path: opt_match.opt_str("certificate-path"),
         unminify_js: opt_match.opt_present("unminify-js"),
+        print_pwm: opt_match.opt_present("print-pwm"),
     };
 
     set_defaults(opts);

components/constellation/Cargo.toml

@@ -26,6 +26,7 @@ ipc-channel = "0.8"
 itertools = "0.5"
 layout_traits = {path = "../layout_traits"}
 log = "0.3.5"
+metrics = {path = "../metrics"}
 msg = {path = "../msg"}
 net = {path = "../net"}
 net_traits = {path = "../net_traits"}

components/constellation/lib.rs

@@ -26,6 +26,7 @@ extern crate itertools;
 extern crate layout_traits;
 #[macro_use]
 extern crate log;
+extern crate metrics;
 extern crate msg;
 extern crate net;
 extern crate net_traits;

components/constellation/pipeline.rs

@@ -14,6 +14,7 @@ use ipc_channel::Error;
 use ipc_channel::ipc::{self, IpcReceiver, IpcSender};
 use ipc_channel::router::ROUTER;
 use layout_traits::LayoutThreadFactory;
+use metrics::PaintTimeMetrics;
 use msg::constellation_msg::{BrowsingContextId, TopLevelBrowsingContextId, FrameType, PipelineId, PipelineNamespaceId};
 use net::image_cache::ImageCacheImpl;
 use net_traits::{IpcSend, ResourceThreads};
@@ -471,6 +472,7 @@ impl UnprivilegedPipelineContent {
               STF: ScriptThreadFactory<Message=Message>
     {
         let image_cache = Arc::new(ImageCacheImpl::new(self.webrender_api_sender.create_api()));
+        let paint_time_metrics = PaintTimeMetrics::new(self.time_profiler_chan.clone());
         let layout_pair = STF::create(InitialScriptState {
             id: self.id,
             browsing_context_id: self.browsing_context_id,
@@ -490,7 +492,7 @@ impl UnprivilegedPipelineContent {
             window_size: self.window_size,
             pipeline_namespace_id: self.pipeline_namespace_id,
             content_process_shutdown_chan: self.script_content_process_shutdown_chan,
-            webvr_thread: self.webvr_thread
+            webvr_thread: self.webvr_thread,
         }, self.load_data.clone());
 
         LTF::create(self.id,
@@ -508,7 +510,8 @@ impl UnprivilegedPipelineContent {
                     Some(self.layout_content_process_shutdown_chan),
                     self.webrender_api_sender,
                     self.prefs.get("layout.threads").expect("exists").value()
-                        .as_u64().expect("count") as usize);
+                        .as_u64().expect("count") as usize,
+                    paint_time_metrics);
 
         if wait_for_completion {
             let _ = self.script_content_process_shutdown_port.recv();

components/layout_thread/Cargo.toml

@@ -23,6 +23,7 @@ layout = {path = "../layout"}
 layout_traits = {path = "../layout_traits"}
 lazy_static = "0.2"
 log = "0.3.5"
+metrics = {path = "../metrics"}
 msg = {path = "../msg"}
 net_traits = {path = "../net_traits"}
 parking_lot = {version = "0.4", features = ["nightly"]}

components/layout_thread/lib.rs

@@ -27,6 +27,7 @@ extern crate layout_traits;
 extern crate lazy_static;
 #[macro_use]
 extern crate log;
+extern crate metrics;
 extern crate msg;
 extern crate net_traits;
 extern crate parking_lot;
@@ -83,6 +84,7 @@ use layout::traversal::{ComputeAbsolutePositions, RecalcStyleAndConstructFlows};
 use layout::webrender_helpers::WebRenderDisplayListConverter;
 use layout::wrapper::LayoutNodeLayoutData;
 use layout_traits::LayoutThreadFactory;
+use metrics::{PaintTimeMetrics, ProfilerMetadataFactory};
 use msg::constellation_msg::PipelineId;
 use msg::constellation_msg::TopLevelBrowsingContextId;
 use net_traits::image_cache::{ImageCache, UsePlaceholder};
@@ -248,7 +250,10 @@ pub struct LayoutThread {
     layout_threads: usize,
 
     /// Which quirks mode are we rendering the document in?
-    quirks_mode: Option<QuirksMode>
+    quirks_mode: Option<QuirksMode>,
+
+    /// Paint time metrics.
+    paint_time_metrics: PaintTimeMetrics,
 }
 
 impl LayoutThreadFactory for LayoutThread {
@@ -269,7 +274,8 @@ impl LayoutThreadFactory for LayoutThread {
               mem_profiler_chan: mem::ProfilerChan,
               content_process_shutdown_chan: Option<IpcSender<()>>,
               webrender_api_sender: webrender_api::RenderApiSender,
-              layout_threads: usize) {
+              layout_threads: usize,
+              paint_time_metrics: PaintTimeMetrics) {
         thread::Builder::new().name(format!("LayoutThread {:?}", id)).spawn(move || {
             thread_state::initialize(thread_state::LAYOUT);
 
@@ -291,7 +297,8 @@ impl LayoutThreadFactory for LayoutThread {
                                                time_profiler_chan,
                                                mem_profiler_chan.clone(),
                                                webrender_api_sender,
-                                               layout_threads);
+                                               layout_threads,
+                                               paint_time_metrics);
 
                 let reporter_name = format!("layout-reporter-{}", id);
                 mem_profiler_chan.run_with_memory_reporting(|| {
@@ -452,7 +459,8 @@ impl LayoutThread {
            time_profiler_chan: time::ProfilerChan,
            mem_profiler_chan: mem::ProfilerChan,
            webrender_api_sender: webrender_api::RenderApiSender,
-           layout_threads: usize)
+           layout_threads: usize,
+           paint_time_metrics: PaintTimeMetrics)
            -> LayoutThread {
         let device = Device::new(
             MediaType::Screen,
@@ -551,6 +559,7 @@ impl LayoutThread {
                 },
             layout_threads: layout_threads,
             quirks_mode: None,
+            paint_time_metrics: paint_time_metrics,
         }
     }
 
@@ -733,7 +742,10 @@ impl LayoutThread {
                 debug!("layout: ExitNow received");
                 self.exit_now();
                 return false
-            }
+            },
+            Msg::SetNavigationStart(time) => {
+                self.paint_time_metrics.set_navigation_start(time);
+            },
         }
 
         true
@@ -785,7 +797,8 @@ impl LayoutThread {
                              self.mem_profiler_chan.clone(),
                              info.content_process_shutdown_chan,
                              self.webrender_api.clone_sender(),
-                             info.layout_threads);
+                             info.layout_threads,
+                             info.paint_time_metrics);
     }
 
     /// Enters a quiescent state in which no new messages will be processed until an `ExitNow` is
@@ -1020,6 +1033,12 @@ impl LayoutThread {
             self.epoch.set(epoch);
 
             let viewport_size = webrender_api::LayoutSize::from_untyped(&viewport_size);
+
+            // Set paint metrics if needed right before sending the display list to WebRender.
+            // XXX At some point, we may want to set this metric from WebRender itself.
+            self.paint_time_metrics.maybe_set_first_paint(self);
+            self.paint_time_metrics.maybe_set_first_contentful_paint(self, &display_list);
+
             self.webrender_api.set_display_list(
                 Some(get_root_flow_background_color(layout_root)),
                 webrender_api::Epoch(epoch.0),
@@ -1655,6 +1674,11 @@ impl LayoutThread {
     }
 }
 
+impl ProfilerMetadataFactory for LayoutThread {
+    fn new_metadata(&self) -> Option<TimerMetadata> {
+        self.profiler_metadata()
+    }
+}
 
 // The default computed value for background-color is transparent (see
 // http://dev.w3.org/csswg/css-backgrounds/#background-color). However, we

components/layout_traits/Cargo.toml

@@ -12,6 +12,7 @@ path = "lib.rs"
 [dependencies]
 gfx = {path = "../gfx"}
 ipc-channel = "0.8"
+metrics = {path = "../metrics"}
 msg = {path = "../msg"}
 net_traits = {path = "../net_traits"}
 profile_traits = {path = "../profile_traits"}

components/layout_traits/lib.rs

@@ -6,6 +6,7 @@
 
 extern crate gfx;
 extern crate ipc_channel;
+extern crate metrics;
 extern crate msg;
 extern crate net_traits;
 extern crate profile_traits;
@@ -20,6 +21,7 @@ extern crate webrender_api;
 
 use gfx::font_cache_thread::FontCacheThread;
 use ipc_channel::ipc::{IpcReceiver, IpcSender};
+use metrics::PaintTimeMetrics;
 use msg::constellation_msg::PipelineId;
 use msg::constellation_msg::TopLevelBrowsingContextId;
 use net_traits::image_cache::ImageCache;
@@ -48,5 +50,6 @@ pub trait LayoutThreadFactory {
               mem_profiler_chan: mem::ProfilerChan,
               content_process_shutdown_chan: Option<IpcSender<()>>,
               webrender_api_sender: webrender_api::RenderApiSender,
-              layout_threads: usize);
+              layout_threads: usize,
+              paint_time_metrics: PaintTimeMetrics);
 }

components/metrics/Cargo.toml

@@ -0,0 +1,16 @@
+[package]
+name = "metrics"
+version = "0.0.1"
+authors = ["The Servo Project Developers"]
+license = "MPL-2.0"
+publish = false
+
+[lib]
+name = "metrics"
+path = "lib.rs"
+
+[dependencies]
+gfx = {path = "../gfx"}
+profile_traits = {path = "../profile_traits"}
+servo_config = {path = "../config"}
+time = "0.1.12"

components/metrics/lib.rs

@@ -0,0 +1,113 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+extern crate gfx;
+extern crate profile_traits;
+extern crate servo_config;
+extern crate time;
+
+use gfx::display_list::{DisplayItem, DisplayList};
+use profile_traits::time::{ProfilerChan, ProfilerCategory, send_profile_data};
+use profile_traits::time::TimerMetadata;
+use servo_config::opts;
+use std::cell::Cell;
+
+pub trait ProfilerMetadataFactory {
+    fn new_metadata(&self) -> Option<TimerMetadata>;
+}
+
+macro_rules! make_time_setter(
+    ( $attr:ident, $func:ident, $category:ident, $label:expr ) => (
+        fn $func<T>(&self, profiler_metadata_factory: &T)
+            where T: ProfilerMetadataFactory {
+            let navigation_start = match self.navigation_start {
+                Some(time) => time,
+                None => {
+                    println!("Trying to set metric before navigation start");
+                    return;
+                }
+            };
+
+            let now = time::precise_time_ns() as f64;
+            let time = now - navigation_start;
+            self.$attr.set(Some(time));
+
+            // Send the metric to the time profiler.
+            send_profile_data(ProfilerCategory::$category,
+                              profiler_metadata_factory.new_metadata(),
+                              &self.time_profiler_chan,
+                              time as u64, time as u64, 0, 0);
+
+            // Print the metric to console if the print-pwm option was given.
+            if opts::get().print_pwm {
+                println!("{:?} {:?}", $label, time);
+            }
+        }
+    );
+);
+
+pub struct PaintTimeMetrics {
+    navigation_start: Option<f64>,
+    first_paint: Cell<Option<f64>>,
+    first_contentful_paint: Cell<Option<f64>>,
+    time_profiler_chan: ProfilerChan,
+}
+
+impl PaintTimeMetrics {
+    pub fn new(time_profiler_chan: ProfilerChan)
+        -> PaintTimeMetrics {
+        PaintTimeMetrics {
+            navigation_start: None,
+            first_paint: Cell::new(None),
+            first_contentful_paint: Cell::new(None),
+            time_profiler_chan: time_profiler_chan,
+        }
+    }
+
+    pub fn set_navigation_start(&mut self, time: f64) {
+        self.navigation_start = Some(time);
+    }
+
+    make_time_setter!(first_paint, set_first_paint,
+                      TimeToFirstPaint,
+                      "first-paint");
+    make_time_setter!(first_contentful_paint, set_first_contentful_paint,
+                      TimeToFirstContentfulPaint,
+                      "first-contentful-paint");
+
+    pub fn maybe_set_first_paint<T>(&self, profiler_metadata_factory: &T)
+        where T: ProfilerMetadataFactory {
+        {
+            if self.first_paint.get().is_some() {
+                return;
+            }
+        }
+
+        self.set_first_paint(profiler_metadata_factory);
+    }
+
+    pub fn maybe_set_first_contentful_paint<T>(&self, profiler_metadata_factory: &T,
+                                               display_list: &DisplayList)
+        where T: ProfilerMetadataFactory {
+        {
+            if self.first_contentful_paint.get().is_some() {
+                return;
+            }
+        }
+
+        // Analyze display list to figure out if this is the first contentful
+        // paint (i.e. the display list contains items of type text, image,
+        // non-white canvas or SVG)
+        for item in &display_list.list {
+            match item {
+                &DisplayItem::Text(_) |
+                &DisplayItem::Image(_) => {
+                    self.set_first_contentful_paint(profiler_metadata_factory);
+                    return;
+                },
+                _ => (),
+            }
+        }
+    }
+}

components/profile/time.rs

@@ -154,6 +154,8 @@ impl Formattable for ProfilerCategory {
             ProfilerCategory::ScriptExitFullscreen => "Script Exit Fullscreen",
             ProfilerCategory::ScriptWebVREvent => "Script WebVR Event",
             ProfilerCategory::ScriptWorkletEvent => "Script Worklet Event",
+            ProfilerCategory::TimeToFirstPaint => "Time To First Paint",
+            ProfilerCategory::TimeToFirstContentfulPaint => "Time To First Contentful Paint",
             ProfilerCategory::ApplicationHeartbeat => "Application Heartbeat",
         };
         format!("{}{}", padding, name)

components/profile_traits/time.rs

@@ -90,6 +90,8 @@ pub enum ProfilerCategory {
     ScriptExitFullscreen = 0x78,
     ScriptWebVREvent = 0x79,
     ScriptWorkletEvent = 0x7a,
+    TimeToFirstPaint = 0x80,
+    TimeToFirstContentfulPaint = 0x81,
     ApplicationHeartbeat = 0x90,
 }
 

components/script/Cargo.toml

@@ -56,6 +56,7 @@ jstraceable_derive = {path = "../jstraceable_derive"}
 lazy_static = "0.2"
 libc = "0.2"
 log = "0.3.5"
+metrics = {path = "../metrics"}
 mime = "0.2.1"
 mime_guess = "1.8.0"
 msg = {path = "../msg"}

components/script/lib.rs

@@ -64,6 +64,7 @@ extern crate lazy_static;
 extern crate libc;
 #[macro_use]
 extern crate log;
+extern crate metrics;
 #[macro_use]
 extern crate mime;
 extern crate mime_guess;

components/script/script_thread.rs

@@ -71,6 +71,7 @@ use js::jsapi::{JSTracer, SetWindowProxyClass};
 use js::jsval::UndefinedValue;
 use js::rust::Runtime;
 use mem::heap_size_of_self_and_children;
+use metrics::PaintTimeMetrics;
 use microtask::{MicrotaskQueue, Microtask};
 use msg::constellation_msg::{BrowsingContextId, FrameType, PipelineId, PipelineNamespace, TopLevelBrowsingContextId};
 use net_traits::{FetchMetadata, FetchResponseListener, FetchResponseMsg};
@@ -176,6 +177,8 @@ impl InProgressLoad {
            url: ServoUrl,
            origin: MutableOrigin) -> InProgressLoad {
         let current_time = get_time();
+        let navigation_start_precise = precise_time_ns() as f64;
+        layout_chan.send(message::Msg::SetNavigationStart(navigation_start_precise)).unwrap();
         InProgressLoad {
             pipeline_id: id,
             browsing_context_id: browsing_context_id,
@@ -188,7 +191,7 @@ impl InProgressLoad {
             url: url,
             origin: origin,
             navigation_start: (current_time.sec * 1000 + current_time.nsec as i64 / 1000000) as u64,
-            navigation_start_precise: precise_time_ns() as f64,
+            navigation_start_precise: navigation_start_precise,
         }
     }
 }
@@ -1453,6 +1456,7 @@ impl ScriptThread {
             image_cache: self.image_cache.clone(),
             content_process_shutdown_chan: content_process_shutdown_chan,
             layout_threads: layout_threads,
+            paint_time_metrics: PaintTimeMetrics::new(self.time_profiler_chan.clone()),
         });
 
         // Pick a layout thread, any layout thread

components/script_layout_interface/Cargo.toml

@@ -22,6 +22,7 @@ html5ever = "0.18"
 ipc-channel = "0.8"
 libc = "0.2"
 log = "0.3.5"
+metrics = {path = "../metrics"}
 msg = {path = "../msg"}
 net_traits = {path = "../net_traits"}
 profile_traits = {path = "../profile_traits"}

components/script_layout_interface/lib.rs

@@ -24,6 +24,7 @@ extern crate ipc_channel;
 extern crate libc;
 #[macro_use]
 extern crate log;
+extern crate metrics;
 extern crate msg;
 extern crate net_traits;
 extern crate profile_traits;

components/script_layout_interface/message.rs

@@ -7,6 +7,7 @@ use app_units::Au;
 use euclid::{Point2D, Rect};
 use gfx_traits::Epoch;
 use ipc_channel::ipc::{IpcReceiver, IpcSender};
+use metrics::PaintTimeMetrics;
 use msg::constellation_msg::PipelineId;
 use net_traits::image_cache::ImageCache;
 use profile_traits::mem::ReportsChan;
@@ -89,6 +90,9 @@ pub enum Msg {
 
     /// Tells layout that script has added some paint worklet modules.
     RegisterPaint(Atom, Vec<Atom>, Arc<Painter>),
+
+    /// Send to layout the precise time when the navigation started.
+    SetNavigationStart(f64),
 }
 
 
@@ -158,4 +162,5 @@ pub struct NewLayoutThreadInfo {
     pub image_cache: Arc<ImageCache>,
     pub content_process_shutdown_chan: Option<IpcSender<()>>,
     pub layout_threads: usize,
+    pub paint_time_metrics: PaintTimeMetrics,
 }

components/script_traits/Cargo.toml

@@ -23,6 +23,7 @@ hyper = "0.10"
 hyper_serde = "0.7"
 ipc-channel = "0.8"
 libc = "0.2"
+metrics = {path = "../metrics"}
 msg = {path = "../msg"}
 net_traits = {path = "../net_traits"}
 offscreen_gl_context = { version = "0.11", features = ["serde"] }