From 2ffbe5398970e54ad55d3e53b495ee6651b64f4c Mon Sep 17 00:00:00 2001 From: ddh Date: Mon, 2 Oct 2017 14:52:39 +0100 Subject: [PATCH] added time to interactive metrics, refactored metrics to use traits changed task macro to take pipeline info --- Cargo.lock | 5 + components/layout_thread/lib.rs | 2 +- components/metrics/Cargo.toml | 4 + components/metrics/lib.rs | 389 ++++++++++++++---- components/profile/time.rs | 1 + components/profile_traits/time.rs | 7 +- components/script/dom/bindings/trace.rs | 7 +- .../script/dom/dedicatedworkerglobalscope.rs | 9 +- components/script/dom/document.rs | 54 ++- .../script/dom/performancepainttiming.rs | 12 +- components/script/dom/vrdisplay.rs | 3 +- components/script/dom/websocket.rs | 3 +- components/script/dom/window.rs | 14 + components/script/dom/workerglobalscope.rs | 2 +- components/script/dom/worklet.rs | 2 +- components/script/script_runtime.rs | 5 +- components/script/script_thread.rs | 119 +++++- .../script/task_source/dom_manipulation.rs | 1 + components/script/task_source/file_reading.rs | 1 + components/script/task_source/networking.rs | 2 + .../task_source/performance_timeline.rs | 3 +- .../script/task_source/user_interaction.rs | 1 + components/script_traits/lib.rs | 17 +- tests/unit/metrics/interactive_time.rs | 116 ++++++ tests/unit/metrics/lib.rs | 1 + tests/unit/metrics/paint_time.rs | 82 +++- 26 files changed, 727 insertions(+), 135 deletions(-) create mode 100644 tests/unit/metrics/interactive_time.rs diff --git a/Cargo.lock b/Cargo.lock index 76930a80186a..9ae665974e13 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1819,11 +1819,15 @@ dependencies = [ "gfx 0.0.1", "gfx_traits 0.0.1", "ipc-channel 0.9.0 (registry+https://github.com/rust-lang/crates.io-index)", + "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)", + "malloc_size_of 0.0.1", + "malloc_size_of_derive 0.0.1", "msg 0.0.1", "profile_traits 0.0.1", "script_traits 0.0.1", "servo_config 0.0.1", + "time 0.1.37 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -2416,6 +2420,7 @@ version = "0.0.1" dependencies = [ "energy-monitor 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)", "energymon 0.3.0 (git+https://github.com/energymon/energymon-rust.git)", + "heapsize 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)", "ipc-channel 0.9.0 (registry+https://github.com/rust-lang/crates.io-index)", "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", "serde 1.0.14 (registry+https://github.com/rust-lang/crates.io-index)", diff --git a/components/layout_thread/lib.rs b/components/layout_thread/lib.rs index 417ad6b68777..62b36b1e6fed 100644 --- a/components/layout_thread/lib.rs +++ b/components/layout_thread/lib.rs @@ -86,7 +86,7 @@ use layout::wrapper::LayoutNodeLayoutData; use layout_traits::LayoutThreadFactory; use libc::c_void; use malloc_size_of::{MallocSizeOf, MallocSizeOfOps}; -use metrics::{PaintTimeMetrics, ProfilerMetadataFactory}; +use metrics::{PaintTimeMetrics, ProfilerMetadataFactory, ProgressiveWebMetric}; use msg::constellation_msg::PipelineId; use msg::constellation_msg::TopLevelBrowsingContextId; use net_traits::image_cache::{ImageCache, UsePlaceholder}; diff --git a/components/metrics/Cargo.toml b/components/metrics/Cargo.toml index 2420d240da21..0393097669b1 100644 --- a/components/metrics/Cargo.toml +++ b/components/metrics/Cargo.toml @@ -14,7 +14,11 @@ gfx = {path = "../gfx"} gfx_traits = {path = "../gfx_traits"} ipc-channel = "0.9" log = "0.3.5" +malloc_size_of = { path = "../malloc_size_of" } +malloc_size_of_derive = { path = "../malloc_size_of_derive" } msg = {path = "../msg"} +lazy_static = "0.2" profile_traits = {path = "../profile_traits"} script_traits = {path = "../script_traits"} servo_config = {path = "../config"} +time = "0.1" diff --git a/components/metrics/lib.rs b/components/metrics/lib.rs index 6a1259ff173d..d6a8710fe0fd 100644 --- a/components/metrics/lib.rs +++ b/components/metrics/lib.rs @@ -1,16 +1,23 @@ /* 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/. */ +#![feature(custom_attribute)] extern crate gfx; extern crate gfx_traits; extern crate ipc_channel; #[macro_use] +extern crate lazy_static; +#[macro_use] extern crate log; +extern crate malloc_size_of; +#[macro_use] +extern crate malloc_size_of_derive; extern crate msg; extern crate profile_traits; extern crate script_traits; extern crate servo_config; +extern crate time; use gfx::display_list::{DisplayItem, DisplayList}; use gfx_traits::Epoch; @@ -18,60 +25,254 @@ use ipc_channel::ipc::IpcSender; use msg::constellation_msg::PipelineId; use profile_traits::time::{ProfilerChan, ProfilerCategory, send_profile_data}; use profile_traits::time::TimerMetadata; -use script_traits::{ConstellationControlMsg, LayoutMsg, PaintMetricType}; +use script_traits::{ConstellationControlMsg, LayoutMsg, PWMType}; use servo_config::opts; use std::cell::{Cell, RefCell}; +use std::cmp::Ordering; use std::collections::HashMap; +use std::time::{Instant, Duration}; +use time::precise_time_ns; pub trait ProfilerMetadataFactory { fn new_metadata(&self) -> Option; } -macro_rules! make_time_setter( - ( $attr:ident, $func:ident, $category:ident, $label:expr, $metric_type:path ) => ( - fn $func(&self, - profiler_metadata: Option, - paint_time: f64) { - if self.$attr.get().is_some() { - return; - } +pub trait ProgressiveWebMetric { + fn get_navigation_start(&self) -> Option; + fn set_navigation_start(&mut self, time: f64); + fn get_time_profiler_chan(&self) -> &ProfilerChan; + fn send_queued_constellation_msg(&self, name: PWMType, time: f64); +} + +lazy_static!{ + static ref TEN_SECONDS: Duration = Duration::new(10, 0); + pub static ref MAX_TASK_TIME: u64 = 50000000; +} + + +// there should be some requirements on self +// can i have self ? +pub fn set_metric( + pwm: &U, + metadata: Option, + metric_type: PWMType, + category: ProfilerCategory, + attr: &Cell>, + metric_time: Option, +) { + let navigation_start = match pwm.get_navigation_start() { + Some(time) => time, + None => { + warn!("Trying to set metric before navigation start"); + return; + } + }; + + let now = match metric_time { + Some(time) => time, + None => precise_time_ns() as f64, + }; + let time = now - navigation_start; + attr.set(Some(time)); + + // Queue performance observer notification. + pwm.send_queued_constellation_msg(metric_type, time); + + // Send the metric to the time profiler. + send_profile_data( + category, + metadata, + &pwm.get_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!("{:?} {:?}", metric_type, time); + } + +} + +// https://github.com/GoogleChrome/lighthouse/issues/27 +#[derive(MallocSizeOf)] +pub struct InteractiveMetrics { + navigation_start: Cell>, + dom_content_loaded: Cell>, + main_thread_available: Cell>, + time_to_interactive: Cell>, + #[ignore_malloc_size_of = "can't measure channels"] + time_profiler_chan: ProfilerChan, +} + +#[derive(Clone, Copy, Debug, MallocSizeOf)] +pub struct InteractiveWindow { + start: u64, + #[ignore_malloc_size_of = "don't need to measure rn"] //FIXME + instant: Instant, + all_interactive: bool, +} + + +//TODO i don't think all interactive is needed anymore +impl InteractiveWindow { + pub fn new() -> InteractiveWindow { + InteractiveWindow { + start: precise_time_ns(), + instant: Instant::now(), + all_interactive: false, + } + } + + // We need to either start or restart the 10s window + // start: we've added a new document + // restart: there was a task > 50s + // not all documents are interactive + pub fn start_window(&mut self) { + self.start = precise_time_ns(); + self.instant = Instant::now(); + self.unset_all_interactive(); + } + + pub fn needs_check(&self) -> bool { + self.instant.elapsed() > *TEN_SECONDS + } + + pub fn check_interactive(&self) -> bool { + self.all_interactive + } + + pub fn set_all_interactive(&mut self) { + self.all_interactive = true; + } + + pub fn unset_all_interactive(&mut self) { + self.all_interactive = false; + } + + pub fn get_start(&self) -> u64 { + self.start + } + + pub fn elapsed_since_start(&self) -> u64 { + self.instant.elapsed().as_secs() + } + + // ^^^^^^^^^^^^^ expected u64, found struct `MAX_TASK_TIME` + + pub fn max_task_time() -> u64 { + 50000000 + } +} + +#[derive(Debug)] +pub enum InteractiveFlag { + DCL, + TTI, +} + +impl InteractiveMetrics { + pub fn new(time_profiler_chan: ProfilerChan) -> InteractiveMetrics { + InteractiveMetrics { + navigation_start: Cell::new(None), + dom_content_loaded: Cell::new(None), + main_thread_available: Cell::new(None), + time_to_interactive: Cell::new(None), + time_profiler_chan: time_profiler_chan, + } + } - let navigation_start = match self.navigation_start { - Some(time) => time, - None => { - warn!("Trying to set metric before navigation start"); - return; + pub fn set_dom_content_loaded(&self) { + if self.dom_content_loaded.get().is_none() { + self.dom_content_loaded.set(Some(precise_time_ns() as f64)); + } + } + + pub fn set_main_thread_available(&self, time: Option) { + if self.main_thread_available.get().is_none() && time.is_some() { + self.main_thread_available.set(time); + } + } + + pub fn get_dom_content_loaded(&self) -> Option { + self.dom_content_loaded.get() + } + + pub fn get_main_thread_available(&self) -> Option { + self.main_thread_available.get() + } + + // can set either dlc or tti first, but both must be set to actually calc metric + // when the second is set, set_tti is called with appropriate time + pub fn maybe_set_tti( + &self, + profiler_metadata_factory: &T, + time: Option, + metric: InteractiveFlag, + ) where + T: ProfilerMetadataFactory, + { + if self.get_tti().is_some() { + return; + } + match metric { + InteractiveFlag::DCL => self.set_dom_content_loaded(), + InteractiveFlag::TTI => self.set_main_thread_available(time), + } + + let dcl = self.dom_content_loaded.get(); + let mta = self.main_thread_available.get(); + if dcl.is_some() && mta.is_some() { + let metric_time = match dcl.unwrap().partial_cmp(&mta.unwrap()) { + Some(order) => { + match order { + Ordering::Less => mta, + _ => dcl, + } } + None => panic!("no ordering possible. something bad happened"), }; + set_metric( + self, + profiler_metadata_factory.new_metadata(), + PWMType::TimeToInteractive, + ProfilerCategory::TimeToInteractive, + &self.time_to_interactive, + metric_time, + ); - let time = paint_time - navigation_start; - self.$attr.set(Some(time)); + } + } - // Queue performance observer notification. - let msg = ConstellationControlMsg::PaintMetric(self.pipeline_id, - $metric_type, - time); - if let Err(e) = self.script_chan.send(msg) { - warn!("Sending paint metric to script thread failed ({}).", e); - } + pub fn get_tti(&self) -> Option { + self.time_to_interactive.get() + } +} - // Send the metric to the time profiler. - send_profile_data(ProfilerCategory::$category, - profiler_metadata, - &self.time_profiler_chan, - time as u64, time as u64, 0, 0); +// TODO don't impl on ref +impl ProgressiveWebMetric for InteractiveMetrics { + fn get_navigation_start(&self) -> Option { + self.navigation_start.get() + } - // Print the metric to console if the print-pwm option was given. - if opts::get().print_pwm { - println!("{:?} {:?}", $label, time); - } - } - ); -); + fn set_navigation_start(&mut self, time: f64) { + self.navigation_start.set(Some(time)); + } + + fn send_queued_constellation_msg(&self, name: PWMType, time: f64) { + // TODO + } + + fn get_time_profiler_chan(&self) -> &ProfilerChan { + &self.time_profiler_chan + } +} pub struct PaintTimeMetrics { pending_metrics: RefCell, bool)>>, - navigation_start: Option, + navigation_start: Cell>, first_paint: Cell>, first_contentful_paint: Cell>, pipeline_id: PipelineId, @@ -81,14 +282,15 @@ pub struct PaintTimeMetrics { } impl PaintTimeMetrics { - pub fn new(pipeline_id: PipelineId, - time_profiler_chan: ProfilerChan, - constellation_chan: IpcSender, - script_chan: IpcSender) - -> PaintTimeMetrics { + pub fn new( + pipeline_id: PipelineId, + time_profiler_chan: ProfilerChan, + constellation_chan: IpcSender, + script_chan: IpcSender, + ) -> PaintTimeMetrics { PaintTimeMetrics { pending_metrics: RefCell::new(HashMap::new()), - navigation_start: None, + navigation_start: Cell::new(None), first_paint: Cell::new(None), first_contentful_paint: Cell::new(None), pipeline_id, @@ -98,24 +300,34 @@ impl PaintTimeMetrics { } } - pub fn set_navigation_start(&mut self, time: f64) { - self.navigation_start = Some(time); - } + pub fn maybe_set_first_paint(&self, profiler_metadata_factory: &T) + where + T: ProfilerMetadataFactory, + { + { + if self.first_paint.get().is_some() { + return; + } + } - make_time_setter!(first_paint, set_first_paint, - TimeToFirstPaint, - "first-paint", - PaintMetricType::FirstPaint); - make_time_setter!(first_contentful_paint, set_first_contentful_paint, - TimeToFirstContentfulPaint, - "first-contentful-paint", - PaintMetricType::FirstContentfulPaint); + set_metric( + self, + profiler_metadata_factory.new_metadata(), + PWMType::FirstPaint, + ProfilerCategory::TimeToFirstPaint, + &self.first_paint, + None, + ); + } - pub fn maybe_observe_paint_time(&self, - profiler_metadata_factory: &T, - epoch: Epoch, - display_list: &DisplayList) - where T: ProfilerMetadataFactory { + pub fn maybe_observe_paint_time( + &self, + profiler_metadata_factory: &T, + epoch: Epoch, + display_list: &DisplayList, + ) where + T: ProfilerMetadataFactory, + { if self.first_paint.get().is_some() && self.first_contentful_paint.get().is_some() { // If we already set all paint metrics, we just bail out. return; @@ -131,15 +343,15 @@ impl PaintTimeMetrics { &DisplayItem::Image(_) => { is_contentful = true; break; - }, + } _ => (), } } - self.pending_metrics.borrow_mut().insert( - epoch, - (profiler_metadata_factory.new_metadata(), is_contentful) - ); + self.pending_metrics.borrow_mut().insert(epoch, ( + profiler_metadata_factory.new_metadata(), + is_contentful, + )); // Send the pending metric information to the compositor thread. // The compositor will record the current time after painting the @@ -150,9 +362,10 @@ impl PaintTimeMetrics { } } - pub fn maybe_set_metric(&mut self, epoch: Epoch, paint_time: f64) { + pub fn maybe_set_metric(&self, epoch: Epoch, paint_time: f64) { if (self.first_paint.get().is_some() && self.first_contentful_paint.get().is_some()) || - self.navigation_start.is_none() { + self.get_navigation_start().is_none() + { // If we already set all paint metrics or we have not set navigation start yet, // we just bail out. return; @@ -160,16 +373,26 @@ impl PaintTimeMetrics { if let Some(pending_metric) = self.pending_metrics.borrow_mut().remove(&epoch) { let profiler_metadata = pending_metric.0; - self.set_first_paint(profiler_metadata.clone(), paint_time); + set_metric( + self, + profiler_metadata.clone(), + PWMType::FirstPaint, + ProfilerCategory::TimeToFirstPaint, + &self.first_paint, + Some(paint_time), + ); + if pending_metric.1 { - self.set_first_contentful_paint(profiler_metadata, paint_time); + set_metric( + self, + profiler_metadata, + PWMType::FirstContentfulPaint, + ProfilerCategory::TimeToFirstContentfulPaint, + &self.first_contentful_paint, + Some(paint_time), + ); } } - - } - - pub fn get_navigation_start(&self) -> Option { - self.navigation_start } pub fn get_first_paint(&self) -> Option { @@ -180,3 +403,25 @@ impl PaintTimeMetrics { self.first_contentful_paint.get() } } + +// TODO don't impl on ref +impl ProgressiveWebMetric for PaintTimeMetrics { + fn get_navigation_start(&self) -> Option { + self.navigation_start.get() + } + + fn set_navigation_start(&mut self, time: f64) { + self.navigation_start.set(Some(time)); + } + + fn send_queued_constellation_msg(&self, name: PWMType, time: f64) { + let msg = ConstellationControlMsg::PaintMetric(self.pipeline_id, name, time); + if let Err(e) = self.script_chan.send(msg) { + warn!("Sending metric to script thread failed ({}).", e); + } + } + + fn get_time_profiler_chan(&self) -> &ProfilerChan { + &self.time_profiler_chan + } +} diff --git a/components/profile/time.rs b/components/profile/time.rs index cd2aad1d0921..c075272fbc05 100644 --- a/components/profile/time.rs +++ b/components/profile/time.rs @@ -157,6 +157,7 @@ impl Formattable for ProfilerCategory { ProfilerCategory::ScriptPerformanceEvent => "Script Performance Event", ProfilerCategory::TimeToFirstPaint => "Time To First Paint", ProfilerCategory::TimeToFirstContentfulPaint => "Time To First Contentful Paint", + ProfilerCategory::TimeToInteractive => "Time to Interactive", ProfilerCategory::ApplicationHeartbeat => "Application Heartbeat", }; format!("{}{}", padding, name) diff --git a/components/profile_traits/time.rs b/components/profile_traits/time.rs index 096afa2ead7f..3b9316f94780 100644 --- a/components/profile_traits/time.rs +++ b/components/profile_traits/time.rs @@ -12,8 +12,8 @@ use signpost; #[derive(Clone, Debug, Deserialize, Eq, Ord, PartialEq, PartialOrd, Serialize)] pub struct TimerMetadata { - pub url: String, - pub iframe: TimerMetadataFrameType, + pub url: String, + pub iframe: TimerMetadataFrameType, pub incremental: TimerMetadataReflowType, } @@ -93,6 +93,7 @@ pub enum ProfilerCategory { ScriptPerformanceEvent = 0x7b, TimeToFirstPaint = 0x80, TimeToFirstContentfulPaint = 0x81, + TimeToInteractive = 0x82, ApplicationHeartbeat = 0x90, } @@ -113,7 +114,7 @@ pub fn profile(category: ProfilerCategory, profiler_chan: ProfilerChan, callback: F) -> T - where F: FnOnce() -> T + where F: FnOnce() -> T, { if opts::get().signpost { signpost::start(category as u32, &[0, 0, 0, (category as usize) >> 4]); diff --git a/components/script/dom/bindings/trace.rs b/components/script/dom/bindings/trace.rs index 5c7723f17de5..6f5dce2ab145 100644 --- a/components/script/dom/bindings/trace.rs +++ b/components/script/dom/bindings/trace.rs @@ -61,6 +61,7 @@ use js::glue::{CallObjectTracer, CallValueTracer}; use js::jsapi::{GCTraceKindToAscii, Heap, JSObject, JSTracer, TraceKind}; use js::jsval::JSVal; use js::rust::Runtime; +use metrics::{InteractiveMetrics, InteractiveWindow}; use msg::constellation_msg::{BrowsingContextId, FrameType, PipelineId, TopLevelBrowsingContextId}; use net_traits::{Metadata, NetworkError, ReferrerPolicy, ResourceThreads}; use net_traits::filemanager_thread::RelativePos; @@ -283,7 +284,7 @@ unsafe impl JSTraceable for Result { unsafe impl JSTraceable for HashMap where K: Hash + Eq + JSTraceable, V: JSTraceable, - S: BuildHasher + S: BuildHasher, { #[inline] unsafe fn trace(&self, trc: *mut JSTracer) { @@ -296,7 +297,7 @@ unsafe impl JSTraceable for HashMap unsafe impl JSTraceable for HashSet where T: Hash + Eq + JSTraceable, - S: BuildHasher + S: BuildHasher, { #[inline] unsafe fn trace(&self, trc: *mut JSTracer) { @@ -413,6 +414,8 @@ unsafe_no_jsmanaged_fields!(WebGLVertexArrayId); unsafe_no_jsmanaged_fields!(MediaList); unsafe_no_jsmanaged_fields!(WebVRGamepadHand); unsafe_no_jsmanaged_fields!(ScriptToConstellationChan); +unsafe_no_jsmanaged_fields!(InteractiveMetrics); +unsafe_no_jsmanaged_fields!(InteractiveWindow); unsafe impl<'a> JSTraceable for &'a str { #[inline] diff --git a/components/script/dom/dedicatedworkerglobalscope.rs b/components/script/dom/dedicatedworkerglobalscope.rs index 51c52e3f766d..bf2077b743f6 100644 --- a/components/script/dom/dedicatedworkerglobalscope.rs +++ b/components/script/dom/dedicatedworkerglobalscope.rs @@ -196,7 +196,8 @@ impl DedicatedWorkerGlobalScope { println!("error loading script {}", serialized_worker_url); parent_sender.send(CommonScriptMsg::Task( WorkerEvent, - Box::new(SimpleWorkerErrorHandler::new(worker)) + Box::new(SimpleWorkerErrorHandler::new(worker)), + pipeline_id )).unwrap(); return; } @@ -358,6 +359,7 @@ impl DedicatedWorkerGlobalScope { #[allow(unsafe_code)] pub fn forward_error_to_worker_object(&self, error_info: ErrorInfo) { let worker = self.worker.borrow().as_ref().unwrap().clone(); + let pipeline_id = worker.clone().root().global().pipeline_id(); let task = Box::new(task!(forward_error_to_worker_object: move || { let worker = worker.root(); let global = worker.global(); @@ -383,7 +385,7 @@ impl DedicatedWorkerGlobalScope { } })); // TODO: Should use the DOM manipulation task source. - self.parent_sender.send(CommonScriptMsg::Task(WorkerEvent, task)).unwrap(); + self.parent_sender.send(CommonScriptMsg::Task(WorkerEvent, task, Some(pipeline_id))).unwrap(); } } @@ -404,10 +406,11 @@ impl DedicatedWorkerGlobalScopeMethods for DedicatedWorkerGlobalScope { unsafe fn PostMessage(&self, cx: *mut JSContext, message: HandleValue) -> ErrorResult { let data = StructuredCloneData::write(cx, message)?; let worker = self.worker.borrow().as_ref().unwrap().clone(); + let pipeline_id = worker.clone().root().global().pipeline_id(); let task = Box::new(task!(post_worker_message: move || { Worker::handle_message(worker, data); })); - self.parent_sender.send(CommonScriptMsg::Task(WorkerEvent, task)).unwrap(); + self.parent_sender.send(CommonScriptMsg::Task(WorkerEvent, task, Some(pipeline_id))).unwrap(); Ok(()) } diff --git a/components/script/dom/document.rs b/components/script/dom/document.rs index 95408843f075..b9b4542697b3 100644 --- a/components/script/dom/document.rs +++ b/components/script/dom/document.rs @@ -99,6 +99,7 @@ use hyper_serde::Serde; use ipc_channel::ipc::{self, IpcSender}; use js::jsapi::{JSContext, JSRuntime}; use js::jsapi::JS_GetRuntime; +use metrics::{InteractiveFlag, InteractiveMetrics, InteractiveWindow, ProfilerMetadataFactory, ProgressiveWebMetric}; use msg::constellation_msg::{ALT, CONTROL, SHIFT, SUPER}; use msg::constellation_msg::{BrowsingContextId, Key, KeyModifiers, KeyState, TopLevelBrowsingContextId}; use net_traits::{FetchResponseMsg, IpcSend, ReferrerPolicy}; @@ -108,6 +109,7 @@ use net_traits::pub_domains::is_pub_domain; use net_traits::request::RequestInit; use net_traits::response::HttpsState; use num_traits::ToPrimitive; +use profile_traits::time::{TimerMetadata, TimerMetadataFrameType, TimerMetadataReflowType}; use script_layout_interface::message::{Msg, NodesFromPointQueryType, ReflowGoal}; use script_runtime::{CommonScriptMsg, ScriptThreadEventCategory}; use script_thread::{MainThreadScriptMsg, ScriptThread}; @@ -360,6 +362,8 @@ pub struct Document { /// is inserted or removed from the document. /// See https://html.spec.whatwg.org/multipage/#form-owner form_id_listener_map: DomRefCell>>>, + interactive_time: DomRefCell, + tti_window: DomRefCell, } #[derive(JSTraceable, MallocSizeOf)] @@ -1834,6 +1838,9 @@ impl Document { window.reflow(ReflowGoal::Full, ReflowReason::DOMContentLoaded); update_with_current_time_ms(&self.dom_content_loaded_event_end); + // html parsing has finished - set dom content loaded + self.interactive_time.borrow().maybe_set_tti(self, None, InteractiveFlag::DCL); + // Step 4.2. // TODO: client message queue. } @@ -1916,6 +1923,14 @@ impl Document { self.dom_interactive.get() } + pub fn get_interactive_metrics(&self) -> Ref { + self.interactive_time.borrow() + } + + pub fn is_interactive(&self) -> bool { + self.get_interactive_metrics().get_tti().is_some() + } + pub fn get_dom_content_loaded_event_start(&self) -> u64 { self.dom_content_loaded_event_start.get() } @@ -1936,6 +1951,23 @@ impl Document { self.load_event_end.get() } + pub fn start_tti(&self) { + self.tti_window.borrow_mut().start_window(); + } + + /// check tti for this document + /// if it's been 10s since this doc encountered a task over 50ms, then we consider the + /// main thread available and try to set tti + pub fn check_tti(&self) { + if self.is_interactive() { return; } + + if self.tti_window.borrow().needs_check() { + self.get_interactive_metrics().maybe_set_tti(self, + Some(self.tti_window.borrow().get_start() as f64), + InteractiveFlag::TTI); + } + } + // https://html.spec.whatwg.org/multipage/#fire-a-focus-event fn fire_focus_event(&self, focus_event_type: FocusEventType, node: &Node, related_target: Option<&EventTarget>) { let (event_name, does_bubble) = match focus_event_type { @@ -2145,6 +2177,9 @@ impl Document { (DocumentReadyState::Complete, true) }; + let mut interactive_time = InteractiveMetrics::new(window.time_profiler_chan().clone()); + interactive_time.set_navigation_start(window.get_navigation_start()); + Document { node: Node::new_document_node(), window: Dom::from_ref(window), @@ -2236,6 +2271,8 @@ impl Document { dom_count: Cell::new(1), fullscreen_element: MutNullableDom::new(None), form_id_listener_map: Default::default(), + interactive_time: DomRefCell::new(interactive_time), + tti_window: DomRefCell::new(InteractiveWindow::new()), } } @@ -2579,11 +2616,13 @@ impl Document { self.send_to_constellation(event); } + let pipeline_id = self.window().pipeline_id(); + // Step 7 let trusted_pending = Trusted::new(pending); let trusted_promise = TrustedPromise::new(promise.clone()); let handler = ElementPerformFullscreenEnter::new(trusted_pending, trusted_promise, error); - let script_msg = CommonScriptMsg::Task(ScriptThreadEventCategory::EnterFullscreen, handler); + let script_msg = CommonScriptMsg::Task(ScriptThreadEventCategory::EnterFullscreen, handler, pipeline_id); let msg = MainThreadScriptMsg::Common(script_msg); window.main_thread_script_chan().send(msg).unwrap(); @@ -2615,7 +2654,8 @@ impl Document { let trusted_element = Trusted::new(element.r()); let trusted_promise = TrustedPromise::new(promise.clone()); let handler = ElementPerformFullscreenExit::new(trusted_element, trusted_promise); - let script_msg = CommonScriptMsg::Task(ScriptThreadEventCategory::ExitFullscreen, handler); + let pipeline_id = Some(global.pipeline_id()); + let script_msg = CommonScriptMsg::Task(ScriptThreadEventCategory::ExitFullscreen, handler, pipeline_id); let msg = MainThreadScriptMsg::Common(script_msg); window.main_thread_script_chan().send(msg).unwrap(); @@ -2673,6 +2713,16 @@ impl Element { } } +impl ProfilerMetadataFactory for Document { + fn new_metadata(&self) -> Option { + Some(TimerMetadata { + url: String::from(self.url().as_str()), + iframe: TimerMetadataFrameType::RootWindow, + incremental: TimerMetadataReflowType::Incremental, + }) + } +} + impl DocumentMethods for Document { // https://drafts.csswg.org/cssom/#dom-document-stylesheets fn StyleSheets(&self) -> DomRoot { diff --git a/components/script/dom/performancepainttiming.rs b/components/script/dom/performancepainttiming.rs index 4c25e785208c..fb7b8b30209c 100644 --- a/components/script/dom/performancepainttiming.rs +++ b/components/script/dom/performancepainttiming.rs @@ -9,7 +9,7 @@ use dom::bindings::str::DOMString; use dom::globalscope::GlobalScope; use dom::performanceentry::PerformanceEntry; use dom_struct::dom_struct; -use script_traits::PaintMetricType; +use script_traits::PWMType; #[dom_struct] pub struct PerformancePaintTiming { @@ -17,11 +17,11 @@ pub struct PerformancePaintTiming { } impl PerformancePaintTiming { - fn new_inherited(metric_type: PaintMetricType, start_time: f64) - -> PerformancePaintTiming { + fn new_inherited(metric_type: PWMType, start_time: f64) -> PerformancePaintTiming { let name = match metric_type { - PaintMetricType::FirstPaint => DOMString::from("first-paint"), - PaintMetricType::FirstContentfulPaint => DOMString::from("first-contentful-paint"), + PWMType::FirstPaint => DOMString::from("first-paint"), + PWMType::FirstContentfulPaint => DOMString::from("first-contentful-paint"), + _ => DOMString::from(""), }; PerformancePaintTiming { entry: PerformanceEntry::new_inherited(name, @@ -33,7 +33,7 @@ impl PerformancePaintTiming { #[allow(unrooted_must_root)] pub fn new(global: &GlobalScope, - metric_type: PaintMetricType, + metric_type: PWMType, start_time: f64) -> DomRoot { let entry = PerformancePaintTiming::new_inherited(metric_type, start_time); reflect_dom_object(Box::new(entry), global, PerformancePaintTimingBinding::Wrap) diff --git a/components/script/dom/vrdisplay.rs b/components/script/dom/vrdisplay.rs index d63e0f514e02..55d944120955 100644 --- a/components/script/dom/vrdisplay.rs +++ b/components/script/dom/vrdisplay.rs @@ -505,6 +505,7 @@ impl VRDisplay { let (raf_sender, raf_receiver) = mpsc::channel(); let mut near = near_init; let mut far = far_init; + // let pipeline_id = self.global().pipeline_id().clone(); TODO // Initialize compositor api_sender.send_vr(WebVRCommand::Create(display_id)).unwrap(); @@ -515,7 +516,7 @@ impl VRDisplay { let task = Box::new(task!(handle_vrdisplay_raf: move || { this.root().handle_raf(&sender); })); - js_sender.send(CommonScriptMsg::Task(WebVREvent, task)).unwrap(); + js_sender.send(CommonScriptMsg::Task(WebVREvent, task, None)).unwrap(); // Run Sync Poses in parallell on Render thread let msg = WebVRCommand::SyncPoses(display_id, near, far, sync_sender.clone()); diff --git a/components/script/dom/websocket.rs b/components/script/dom/websocket.rs index 47d3a6f3668d..a29aed6f2469 100644 --- a/components/script/dom/websocket.rs +++ b/components/script/dom/websocket.rs @@ -263,9 +263,10 @@ impl WebSocket { address: address, }); + let pipeline_id = self.global().pipeline_id(); self.global() .script_chan() - .send(CommonScriptMsg::Task(WebSocketEvent, task)) + .send(CommonScriptMsg::Task(WebSocketEvent, task, Some(pipeline_id))) .unwrap(); } diff --git a/components/script/dom/window.rs b/components/script/dom/window.rs index 1df5d6490c82..384c46a04fb4 100644 --- a/components/script/dom/window.rs +++ b/components/script/dom/window.rs @@ -304,6 +304,11 @@ impl Window { } } + /// Get a sender to the time profiler thread. + pub fn time_profiler_chan(&self) -> &TimeProfilerChan { + self.globalscope.time_profiler_chan() + } + pub fn origin(&self) -> &MutableOrigin { self.globalscope.origin() } @@ -1040,6 +1045,10 @@ impl Window { } } + pub fn get_navigation_start(&self) -> f64 { + self.navigation_start_precise.get() + } + /// Cancels all the tasks associated with that window. /// /// This sets the current `ignore_further_async_events` sentinel value to @@ -1854,6 +1863,10 @@ impl Window { WindowBinding::Wrap(runtime.cx(), win) } } + + pub fn pipeline_id(&self) -> Option { + Some(self.upcast::().pipeline_id()) + } } fn should_move_clip_rect(clip_rect: Rect, new_viewport: Rect) -> bool { @@ -1962,6 +1975,7 @@ impl Window { let _ = self.script_chan.send(CommonScriptMsg::Task( ScriptThreadEventCategory::DomEvent, Box::new(self.task_canceller().wrap_task(task)), + self.pipeline_id() )); } } diff --git a/components/script/dom/workerglobalscope.rs b/components/script/dom/workerglobalscope.rs index 4ebfd67a4869..6638f1d19220 100644 --- a/components/script/dom/workerglobalscope.rs +++ b/components/script/dom/workerglobalscope.rs @@ -386,7 +386,7 @@ impl WorkerGlobalScope { pub fn process_event(&self, msg: CommonScriptMsg) { match msg { - CommonScriptMsg::Task(_, task) => { + CommonScriptMsg::Task(_, task, _) => { task.run_box() }, CommonScriptMsg::CollectReports(reports_chan) => { diff --git a/components/script/dom/worklet.rs b/components/script/dom/worklet.rs index ca48ec08fe83..e49163bb799f 100644 --- a/components/script/dom/worklet.rs +++ b/components/script/dom/worklet.rs @@ -646,7 +646,7 @@ impl WorkletThread { where T: TaskBox + 'static, { - let msg = CommonScriptMsg::Task(ScriptThreadEventCategory::WorkletEvent, Box::new(task)); + let msg = CommonScriptMsg::Task(ScriptThreadEventCategory::WorkletEvent, Box::new(task), None); let msg = MainThreadScriptMsg::Common(msg); self.global_init.to_script_thread_sender.send(msg).expect("Worklet thread outlived script thread."); } diff --git a/components/script/script_runtime.rs b/components/script/script_runtime.rs index 7d3e5e60e1c4..57e1bbd07557 100644 --- a/components/script/script_runtime.rs +++ b/components/script/script_runtime.rs @@ -22,6 +22,7 @@ use js::jsapi::{JSObject, RuntimeOptionsRef, SetPreserveWrapperCallback, SetEnqu use js::panic::wrap_panic; use js::rust::Runtime as RustRuntime; use microtask::{EnqueuedPromiseCallback, Microtask}; +use msg::constellation_msg::PipelineId; use profile_traits::mem::{Report, ReportKind, ReportsChan}; use script_thread::trace_thread; use servo_config::opts; @@ -44,14 +45,14 @@ pub enum CommonScriptMsg { /// supplied channel. CollectReports(ReportsChan), /// Generic message that encapsulates event handling. - Task(ScriptThreadEventCategory, Box), + Task(ScriptThreadEventCategory, Box, Option), } impl fmt::Debug for CommonScriptMsg { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { match *self { CommonScriptMsg::CollectReports(_) => write!(f, "CollectReports(...)"), - CommonScriptMsg::Task(ref category, ref task) => { + CommonScriptMsg::Task(ref category, ref task, _) => { f.debug_tuple("Task").field(category).field(task).finish() }, } diff --git a/components/script/script_thread.rs b/components/script/script_thread.rs index 1a45b08e54bd..1fe8c47b7bc3 100644 --- a/components/script/script_thread.rs +++ b/components/script/script_thread.rs @@ -16,6 +16,7 @@ //! takes over the response body. Once parsing is complete, the document lifecycle for loading //! a page runs its course and the script thread returns to processing events in the main event //! loop. +#![feature(box_syntax)] use bluetooth_traits::BluetoothRequest; use canvas_traits::webgl::WebGLPipeline; @@ -74,7 +75,7 @@ use js::jsapi::{JSTracer, SetWindowProxyClass}; use js::jsval::UndefinedValue; use malloc_size_of::MallocSizeOfOps; use mem::malloc_size_of_including_self; -use metrics::PaintTimeMetrics; +use metrics::{InteractiveWindow, PaintTimeMetrics}; use microtask::{MicrotaskQueue, Microtask}; use msg::constellation_msg::{BrowsingContextId, FrameType, PipelineId, PipelineNamespace, TopLevelBrowsingContextId}; use net_traits::{FetchMetadata, FetchResponseListener, FetchResponseMsg}; @@ -91,7 +92,7 @@ use script_traits::{CompositorEvent, ConstellationControlMsg}; use script_traits::{DiscardBrowsingContext, DocumentActivity, EventResult}; use script_traits::{InitialScriptState, JsEvalResult, LayoutMsg, LoadData}; use script_traits::{MouseButton, MouseEventType, MozBrowserEvent, NewLayoutInfo}; -use script_traits::{PaintMetricType, Painter, ScriptMsg, ScriptThreadFactory}; +use script_traits::{PWMType, Painter, ScriptMsg, ScriptThreadFactory}; use script_traits::{ScriptToConstellationChan, TimerEvent, TimerSchedulerMsg}; use script_traits::{TimerSource, TouchEventType, TouchId, UntrustedNodeAddress}; use script_traits::{UpdatePipelineIdReason, WindowSizeData, WindowSizeType}; @@ -345,6 +346,10 @@ impl Documents { self.map.get(&pipeline_id).map(|doc| DomRoot::from_ref(&**doc)) } + pub fn len(&self) -> usize { + self.map.len() + } + pub fn find_window(&self, pipeline_id: PipelineId) -> Option> { self.find_document(pipeline_id).map(|doc| DomRoot::from_ref(doc.window())) } @@ -681,7 +686,8 @@ impl ScriptThread { SCRIPT_THREAD_ROOT.with(|root| { if let Some(script_thread) = root.get() { let script_thread = unsafe { &*script_thread }; - script_thread.profile_event(ScriptThreadEventCategory::AttachLayout, || { + let p_id = Some(new_layout_info.new_pipeline_id); + script_thread.profile_event(ScriptThreadEventCategory::AttachLayout, p_id, || { script_thread.handle_new_layout(new_layout_info, origin); }) } @@ -727,8 +733,8 @@ impl ScriptThread { pipeline_id: PipelineId, name: Atom, properties: Vec, - painter: Box, - ) { + painter: Box) + { let window = self.documents.borrow().find_window(pipeline_id); let window = match window { Some(window) => window, @@ -840,7 +846,7 @@ impl ScriptThread { control_chan: state.control_chan, control_port: control_port, script_sender: state.script_to_constellation_chan.sender.clone(), - time_profiler_chan: state.time_profiler_chan, + time_profiler_chan: state.time_profiler_chan.clone(), mem_profiler_chan: state.mem_profiler_chan, devtools_chan: state.devtools_chan, @@ -964,7 +970,8 @@ impl ScriptThread { // child list yet, causing the find() to fail. FromConstellation(ConstellationControlMsg::AttachLayout( new_layout_info)) => { - self.profile_event(ScriptThreadEventCategory::AttachLayout, || { + //FIXME there should be a pipeline id + self.profile_event(ScriptThreadEventCategory::AttachLayout, None, || { // If this is an about:blank load, it must share the creator's origin. // This must match the logic in the constellation when creating a new pipeline let origin = if new_layout_info.load_data.url.as_str() != "about:blank" { @@ -986,17 +993,17 @@ impl ScriptThread { } FromConstellation(ConstellationControlMsg::Resize(id, size, size_type)) => { // step 7.7 - self.profile_event(ScriptThreadEventCategory::Resize, || { + self.profile_event(ScriptThreadEventCategory::Resize, Some(id), || { self.handle_resize(id, size, size_type); }) } FromConstellation(ConstellationControlMsg::Viewport(id, rect)) => { - self.profile_event(ScriptThreadEventCategory::SetViewport, || { + self.profile_event(ScriptThreadEventCategory::SetViewport, Some(id), || { self.handle_viewport(id, rect); }) } FromConstellation(ConstellationControlMsg::SetScrollState(id, scroll_state)) => { - self.profile_event(ScriptThreadEventCategory::SetScrollState, || { + self.profile_event(ScriptThreadEventCategory::SetScrollState, Some(id), || { self.handle_set_scroll_state(id, &scroll_state); }) } @@ -1051,9 +1058,11 @@ impl ScriptThread { debug!("Processing events."); for msg in sequential { debug!("Processing event {:?}.", msg); + let category = self.categorize_msg(&msg); + let p_id = self.message_to_pipeline(&msg); - let result = self.profile_event(category, move || { + let result = self.profile_event(category, p_id, move || { match msg { FromConstellation(ConstellationControlMsg::ExitScriptThread) => { self.handle_exit_script_thread_msg(); @@ -1122,7 +1131,7 @@ impl ScriptThread { MixedMessage::FromImageCache(_) => ScriptThreadEventCategory::ImageCacheMsg, MixedMessage::FromScript(ref inner_msg) => { match *inner_msg { - MainThreadScriptMsg::Common(CommonScriptMsg::Task(category, _)) => { + MainThreadScriptMsg::Common(CommonScriptMsg::Task(category, ..)) => { category }, MainThreadScriptMsg::RegisterPaintWorklet { .. } => { @@ -1135,7 +1144,67 @@ impl ScriptThread { } } - fn profile_event(&self, category: ScriptThreadEventCategory, f: F) -> R + fn message_to_pipeline(&self, msg: &MixedMessage) -> Option { + use script_traits::ConstellationControlMsg::*; + match *msg { + MixedMessage::FromConstellation(ref inner_msg) => { + match *inner_msg { + NavigationResponse(id, _) => Some(id), + AttachLayout(ref new_layout_info) => Some(new_layout_info.new_pipeline_id), + Resize(id, ..) => Some(id), + ResizeInactive(id, ..) => Some(id), + ExitPipeline(id, ..) => Some(id), + ExitScriptThread => None, + SendEvent(id, ..) => Some(id), + Viewport(id, ..) => Some(id), + SetScrollState(id, ..) => Some(id), + GetTitle(id) => Some(id), + SetDocumentActivity(id, ..) => Some(id), + ChangeFrameVisibilityStatus(id, ..) => Some(id), + NotifyVisibilityChange(id, ..) => Some(id), + Navigate(id, ..) => Some(id), + PostMessage(id, ..) => Some(id), + MozBrowserEvent(id, ..) => Some(id), + UpdatePipelineId(_, _, id, _) => Some(id), + FocusIFrame(id, ..) => Some(id), + WebDriverScriptCommand(id, ..) => Some(id), + TickAllAnimations(id) => Some(id), + TransitionEnd(..) => None, + WebFontLoaded(id) => Some(id), + DispatchIFrameLoadEvent { .. } => None, + DispatchStorageEvent(id, ..) => Some(id), + ReportCSSError(id, ..) => Some(id), + Reload(id, ..) => Some(id), + WebVREvents(id, ..) => Some(id), + PaintMetric(..) => None, + InteractiveMetric(..) => None, + } + }, + MixedMessage::FromDevtools(_) => None, + MixedMessage::FromScript(ref inner_msg) => { + match *inner_msg { + MainThreadScriptMsg::Common(CommonScriptMsg::Task(_, _, pipeline_id)) => + pipeline_id, + MainThreadScriptMsg::Common(_) => None, //TODO double check + MainThreadScriptMsg::ExitWindow(pipeline_id) => Some(pipeline_id), + MainThreadScriptMsg::Navigate(pipeline_id, ..) => Some(pipeline_id), + MainThreadScriptMsg::WorkletLoaded(pipeline_id) => Some(pipeline_id), + MainThreadScriptMsg::RegisterPaintWorklet { pipeline_id, .. } => Some(pipeline_id), + MainThreadScriptMsg::DispatchJobQueue { .. } => None, + } + }, + MixedMessage::FromImageCache((pipeline_id, _)) => Some(pipeline_id), + MixedMessage::FromScheduler(ref timer_event) => { + let TimerEvent(source, _) = *timer_event; + match source { + TimerSource::FromWindow(pipeline_id) => Some(pipeline_id), + _ => None + } + } + } + } + + fn profile_event(&self, category: ScriptThreadEventCategory, p_id: Option, f: F) -> R where F: FnOnce() -> R { if opts::get().profile_script_events { let profiler_cat = match category { @@ -1169,7 +1238,24 @@ impl ScriptThread { ScriptThreadEventCategory::ExitFullscreen => ProfilerCategory::ScriptExitFullscreen, ScriptThreadEventCategory::PerformanceTimelineTask => ProfilerCategory::ScriptPerformanceEvent, }; - profile(profiler_cat, None, self.time_profiler_chan.clone(), f) + + let start = precise_time_ns(); + let t = profile(profiler_cat, None, self.time_profiler_chan.clone(), f); + let end = precise_time_ns(); + debug!("Task {:?} took {}", category, end - start); // TODO do we want to do anything with this? + + for (doc_id, doc) in self.documents.borrow().iter() { + match p_id { + Some(p_id) => { + if p_id == doc_id && end - start > InteractiveWindow::max_task_time() { + doc.start_tti() + } + }, + _ => () + } + doc.check_tti(); + } + t } else { f() } @@ -1240,6 +1326,7 @@ impl ScriptThread { self.handle_webvr_events(pipeline_id, events), ConstellationControlMsg::PaintMetric(pipeline_id, metric_type, metric_value) => self.handle_paint_metric(pipeline_id, metric_type, metric_value), + ConstellationControlMsg::InteractiveMetric(pipeline_id, metric_value) => (), //TODO msg @ ConstellationControlMsg::AttachLayout(..) | msg @ ConstellationControlMsg::Viewport(..) | msg @ ConstellationControlMsg::SetScrollState(..) | @@ -1257,7 +1344,7 @@ impl ScriptThread { MainThreadScriptMsg::ExitWindow(id) => { self.handle_exit_window_msg(id) }, - MainThreadScriptMsg::Common(CommonScriptMsg::Task(_, task)) => { + MainThreadScriptMsg::Common(CommonScriptMsg::Task(_, task, _)) => { task.run_box() } MainThreadScriptMsg::Common(CommonScriptMsg::CollectReports(chan)) => { @@ -2563,7 +2650,7 @@ impl ScriptThread { fn handle_paint_metric(&self, pipeline_id: PipelineId, - metric_type: PaintMetricType, + metric_type: PWMType, metric_value: f64) { let window = self.documents.borrow().find_window(pipeline_id); if let Some(window) = window { diff --git a/components/script/task_source/dom_manipulation.rs b/components/script/task_source/dom_manipulation.rs index 5eb20d2d274f..16db93106932 100644 --- a/components/script/task_source/dom_manipulation.rs +++ b/components/script/task_source/dom_manipulation.rs @@ -37,6 +37,7 @@ impl TaskSource for DOMManipulationTaskSource { let msg = MainThreadScriptMsg::Common(CommonScriptMsg::Task( ScriptThreadEventCategory::ScriptEvent, Box::new(canceller.wrap_task(task)), + None //TODO )); self.0.send(msg).map_err(|_| ()) } diff --git a/components/script/task_source/file_reading.rs b/components/script/task_source/file_reading.rs index fe2ae2e4d179..8f4cdd80ac34 100644 --- a/components/script/task_source/file_reading.rs +++ b/components/script/task_source/file_reading.rs @@ -30,6 +30,7 @@ impl TaskSource for FileReadingTaskSource { self.0.send(CommonScriptMsg::Task( ScriptThreadEventCategory::FileRead, Box::new(canceller.wrap_task(task)), + None //TODO )) } } diff --git a/components/script/task_source/networking.rs b/components/script/task_source/networking.rs index 41795227e5d4..0c2fd8f61621 100644 --- a/components/script/task_source/networking.rs +++ b/components/script/task_source/networking.rs @@ -27,6 +27,7 @@ impl TaskSource for NetworkingTaskSource { self.0.send(CommonScriptMsg::Task( ScriptThreadEventCategory::NetworkEvent, Box::new(canceller.wrap_task(task)), + None )) } } @@ -41,6 +42,7 @@ impl NetworkingTaskSource { self.0.send(CommonScriptMsg::Task( ScriptThreadEventCategory::NetworkEvent, Box::new(task), + None //TODO )) } } diff --git a/components/script/task_source/performance_timeline.rs b/components/script/task_source/performance_timeline.rs index 0de171c4949c..a91865cf02f5 100644 --- a/components/script/task_source/performance_timeline.rs +++ b/components/script/task_source/performance_timeline.rs @@ -40,7 +40,8 @@ impl TaskSource for PerformanceTimelineTaskSource { { let msg = CommonScriptMsg::Task( ScriptThreadEventCategory::PerformanceTimelineTask, - Box::new(canceller.wrap_task(task)) + Box::new(canceller.wrap_task(task)), + None ); self.0.send(msg).map_err(|_| ()) } diff --git a/components/script/task_source/user_interaction.rs b/components/script/task_source/user_interaction.rs index c10e870ac7e7..ba90a26a0807 100644 --- a/components/script/task_source/user_interaction.rs +++ b/components/script/task_source/user_interaction.rs @@ -37,6 +37,7 @@ impl TaskSource for UserInteractionTaskSource { let msg = MainThreadScriptMsg::Common(CommonScriptMsg::Task( ScriptThreadEventCategory::InputEvent, Box::new(canceller.wrap_task(task)), + None )); self.0.send(msg).map_err(|_| ()) } diff --git a/components/script_traits/lib.rs b/components/script_traits/lib.rs index a4e3634296d7..f2210cfd76df 100644 --- a/components/script_traits/lib.rs +++ b/components/script_traits/lib.rs @@ -231,13 +231,15 @@ pub enum DocumentActivity { FullyActive, } -/// The type of recorded paint metric. -#[derive(Deserialize, Serialize)] -pub enum PaintMetricType { - /// Time to First Paint type. +/// Type of recorded progressive web metric +#[derive(Clone, Copy, Debug, Deserialize, Serialize)] +pub enum PWMType { + /// Time to first Paint FirstPaint, - /// Time to First Contentful Paint type. + /// Time to first contentful paint FirstContentfulPaint, + /// Time to interactive + TimeToInteractive, } /// The reason why the pipeline id of an iframe is being updated. @@ -322,7 +324,9 @@ pub enum ConstellationControlMsg { /// Notifies the script thread of WebVR events. WebVREvents(PipelineId, Vec), /// Notifies the script thread about a new recorded paint metric. - PaintMetric(PipelineId, PaintMetricType, f64), + PaintMetric(PipelineId, PWMType, f64), + /// Notifies the script thread of interactive time + InteractiveMetric(PipelineId, f64), } impl fmt::Debug for ConstellationControlMsg { @@ -357,6 +361,7 @@ impl fmt::Debug for ConstellationControlMsg { Reload(..) => "Reload", WebVREvents(..) => "WebVREvents", PaintMetric(..) => "PaintMetric", + InteractiveMetric(..) => "InteractiveMetric" }; write!(formatter, "ConstellationMsg::{}", variant) } diff --git a/tests/unit/metrics/interactive_time.rs b/tests/unit/metrics/interactive_time.rs new file mode 100644 index 000000000000..5652ffbe06d2 --- /dev/null +++ b/tests/unit/metrics/interactive_time.rs @@ -0,0 +1,116 @@ +/* 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/. */ + +use ipc_channel::ipc; +use metrics::{InteractiveMetrics, InteractiveFlag, InteractiveWindow}; +use metrics::{ProfilerMetadataFactory, ProgressiveWebMetric}; +use profile_traits::time::{ProfilerChan, TimerMetadata}; +use time; + +struct DummyProfilerMetadataFactory {} +impl ProfilerMetadataFactory for DummyProfilerMetadataFactory { + fn new_metadata(&self) -> Option { + None + } +} + + +fn test_interactive() -> InteractiveMetrics { + let (sender, _) = ipc::channel().unwrap(); + let profiler_chan = ProfilerChan(sender); + let mut interactive = InteractiveMetrics::new(profiler_chan); + + assert_eq!((&interactive).get_navigation_start(), None); + assert_eq!(interactive.get_tti(), None); + + interactive.set_navigation_start(time::precise_time_ns() as f64); + + interactive +} + +#[test] +fn test_set_dcl() { + let profiler_metadata_factory = DummyProfilerMetadataFactory {}; + + let interactive = test_interactive(); + interactive.maybe_set_tti(&profiler_metadata_factory, None, InteractiveFlag::DCL); + let dcl = interactive.get_dom_content_loaded(); + assert!(dcl.is_some()); + + //try to overwrite + interactive.maybe_set_tti(&profiler_metadata_factory, None, InteractiveFlag::DCL); + assert_eq!(interactive.get_dom_content_loaded(), dcl); + assert_eq!(interactive.get_tti(), None); +} + +#[test] +fn test_set_mta() { + let profiler_metadata_factory = DummyProfilerMetadataFactory {}; + + let interactive = test_interactive(); + let t = time::precise_time_ns(); + interactive.maybe_set_tti( + &profiler_metadata_factory, + Some(t as f64), + InteractiveFlag::TTI, + ); + let mta = interactive.get_main_thread_available(); + assert!(mta.is_some()); + assert_eq!(mta, Some(t as f64)); + + //try to overwrite + interactive.maybe_set_tti( + &profiler_metadata_factory, + Some(time::precise_time_ns() as f64), + InteractiveFlag::TTI, + ); + assert_eq!(interactive.get_main_thread_available(), mta); + assert_eq!(interactive.get_tti(), None); +} + +#[test] +fn test_set_tti_dcl() { + let profiler_metadata_factory = DummyProfilerMetadataFactory {}; + + let interactive = test_interactive(); + let t = time::precise_time_ns(); + interactive.maybe_set_tti( + &profiler_metadata_factory, + Some(t as f64), + InteractiveFlag::TTI, + ); + let mta = interactive.get_main_thread_available(); + assert!(mta.is_some()); + + interactive.maybe_set_tti(&profiler_metadata_factory, None, InteractiveFlag::DCL); + let dcl = interactive.get_dom_content_loaded(); + assert!(dcl.is_some()); + + let interactive_time = dcl.unwrap() - (&interactive).get_navigation_start().unwrap(); + assert_eq!(interactive.get_tti(), Some(interactive_time)); +} + +#[test] +fn test_set_tti_mta() { + let profiler_metadata_factory = DummyProfilerMetadataFactory {}; + + let interactive = test_interactive(); + interactive.maybe_set_tti(&profiler_metadata_factory, None, InteractiveFlag::DCL); + let dcl = interactive.get_dom_content_loaded(); + assert!(dcl.is_some()); + + let t = time::precise_time_ns(); + interactive.maybe_set_tti( + &profiler_metadata_factory, + Some(t as f64), + InteractiveFlag::TTI, + ); + let mta = interactive.get_main_thread_available(); + assert!(mta.is_some()); + + let interactive_time = mta.unwrap() - (&interactive).get_navigation_start().unwrap(); + assert_eq!(interactive.get_tti(), Some(interactive_time)); +} + +// TODO InteractiveWindow tests diff --git a/tests/unit/metrics/lib.rs b/tests/unit/metrics/lib.rs index bde619124935..fc5456a271cc 100644 --- a/tests/unit/metrics/lib.rs +++ b/tests/unit/metrics/lib.rs @@ -14,4 +14,5 @@ extern crate style; extern crate time; #[cfg(test)] +mod interactive_time; mod paint_time; diff --git a/tests/unit/metrics/paint_time.rs b/tests/unit/metrics/paint_time.rs index 2148c71f3ee0..8af87a33c511 100644 --- a/tests/unit/metrics/paint_time.rs +++ b/tests/unit/metrics/paint_time.rs @@ -7,7 +7,7 @@ use gfx::display_list::{BaseDisplayItem, WebRenderImageInfo}; use gfx::display_list::{DisplayItem, DisplayList, ImageDisplayItem}; use gfx_traits::Epoch; use ipc_channel::ipc; -use metrics::{PaintTimeMetrics, ProfilerMetadataFactory}; +use metrics::{PaintTimeMetrics, ProfilerMetadataFactory, ProgressiveWebMetric}; use msg::constellation_msg::TEST_PIPELINE_ID; use net_traits::image::base::PixelFormat; use profile_traits::time::{ProfilerChan, TimerMetadata}; @@ -27,10 +27,27 @@ fn test_paint_metrics_construction() { let profiler_chan = ProfilerChan(sender); let (layout_sender, _) = ipc::channel().unwrap(); let (script_sender, _) = ipc::channel().unwrap(); - let paint_time_metrics = PaintTimeMetrics::new(TEST_PIPELINE_ID, profiler_chan, layout_sender, script_sender); - assert_eq!(paint_time_metrics.get_navigation_start(), None, "navigation start is None"); - assert_eq!(paint_time_metrics.get_first_paint(), None, "first paint is None"); - assert_eq!(paint_time_metrics.get_first_contentful_paint(), None, "first contentful paint is None"); + let paint_time_metrics = PaintTimeMetrics::new( + TEST_PIPELINE_ID, + profiler_chan, + layout_sender, + script_sender, + ); + assert_eq!( + (&paint_time_metrics).get_navigation_start(), + None, + "navigation start is None" + ); + assert_eq!( + paint_time_metrics.get_first_paint(), + None, + "first paint is None" + ); + assert_eq!( + paint_time_metrics.get_first_contentful_paint(), + None, + "first contentful paint is None" + ); } fn test_common(display_list: &DisplayList, epoch: Epoch) -> PaintTimeMetrics { @@ -38,22 +55,40 @@ fn test_common(display_list: &DisplayList, epoch: Epoch) -> PaintTimeMetrics { let profiler_chan = ProfilerChan(sender); let (layout_sender, _) = ipc::channel().unwrap(); let (script_sender, _) = ipc::channel().unwrap(); - let mut paint_time_metrics = PaintTimeMetrics::new(TEST_PIPELINE_ID, profiler_chan, layout_sender, script_sender); + let mut paint_time_metrics = PaintTimeMetrics::new( + TEST_PIPELINE_ID, + profiler_chan, + layout_sender, + script_sender, + ); let dummy_profiler_metadata_factory = DummyProfilerMetadataFactory {}; - paint_time_metrics.maybe_observe_paint_time(&dummy_profiler_metadata_factory, - epoch, - &display_list); + paint_time_metrics.maybe_observe_paint_time( + &dummy_profiler_metadata_factory, + epoch, + &display_list, + ); // Should not set any metric until navigation start is set. paint_time_metrics.maybe_set_metric(epoch, 0.); - assert_eq!(paint_time_metrics.get_first_paint(), None, "first paint is None"); - assert_eq!(paint_time_metrics.get_first_contentful_paint(), None, "first contentful paint is None"); + assert_eq!( + paint_time_metrics.get_first_paint(), + None, + "first paint is None" + ); + assert_eq!( + paint_time_metrics.get_first_contentful_paint(), + None, + "first contentful paint is None" + ); let navigation_start = time::precise_time_ns() as f64; paint_time_metrics.set_navigation_start(navigation_start); - assert_eq!(paint_time_metrics.get_navigation_start().unwrap(), - navigation_start, "navigation start is set"); + assert_eq!( + (&paint_time_metrics).get_navigation_start().unwrap(), + navigation_start, + "navigation start is set" + ); paint_time_metrics } @@ -68,8 +103,15 @@ fn test_first_paint_setter() { let mut paint_time_metrics = test_common(&empty_display_list, epoch); let now = time::precise_time_ns() as f64; paint_time_metrics.maybe_set_metric(epoch, now); - assert!(paint_time_metrics.get_first_paint().is_some(), "first paint is set"); - assert_eq!(paint_time_metrics.get_first_contentful_paint(), None, "first contentful paint is None"); + assert!( + paint_time_metrics.get_first_paint().is_some(), + "first paint is set" + ); + assert_eq!( + paint_time_metrics.get_first_contentful_paint(), + None, + "first contentful paint is None" + ); } #[test] @@ -95,6 +137,12 @@ fn test_first_contentful_paint_setter() { let mut paint_time_metrics = test_common(&display_list, epoch); let now = time::precise_time_ns() as f64; paint_time_metrics.maybe_set_metric(epoch, now); - assert!(paint_time_metrics.get_first_contentful_paint().is_some(), "first contentful paint is set"); - assert!(paint_time_metrics.get_first_paint().is_some(), "first paint is set"); + assert!( + paint_time_metrics.get_first_contentful_paint().is_some(), + "first contentful paint is set" + ); + assert!( + paint_time_metrics.get_first_paint().is_some(), + "first paint is set" + ); }