Wait for actual paint before setting paint related metrics

This commit is contained in:
Fernando Jiménez Moreno 2017-07-26 20:24:42 +02:00
parent 1059ef4fde
commit 1b123400eb
16 changed files with 203 additions and 72 deletions

8
Cargo.lock generated
View file

@ -1715,9 +1715,13 @@ name = "metrics"
version = "0.0.1"
dependencies = [
"gfx 0.0.1",
"gfx_traits 0.0.1",
"ipc-channel 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
"log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)",
"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]]
@ -1726,6 +1730,7 @@ version = "0.0.1"
dependencies = [
"euclid 0.15.1 (registry+https://github.com/rust-lang/crates.io-index)",
"gfx 0.0.1",
"gfx_traits 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",
@ -2597,7 +2602,6 @@ 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",
"profile_traits 0.0.1",

View file

@ -186,6 +186,13 @@ pub struct IOCompositor<Window: WindowMethods> {
/// GL functions interface (may be GL or GLES)
gl: Rc<gl::Gl>,
/// Map of the pending paint metrics per layout thread.
/// The layout thread for each specific pipeline expects the compositor to
/// paint frames with specific given IDs (epoch). Once the compositor paints
/// these frames, it records the paint time for each of them and sends the
/// metric to the corresponding layout thread.
pending_paint_metrics: HashMap<PipelineId, Epoch>,
}
#[derive(Copy, Clone)]
@ -371,6 +378,7 @@ impl<Window: WindowMethods> IOCompositor<Window> {
webrender: state.webrender,
webrender_document: state.webrender_document,
webrender_api: state.webrender_api,
pending_paint_metrics: HashMap::new(),
}
}
@ -593,6 +601,10 @@ impl<Window: WindowMethods> IOCompositor<Window> {
self.window.set_fullscreen_state(top_level_browsing_context_id, state);
}
(Msg::PendingPaintMetric(pipeline_id, epoch), _) => {
self.pending_paint_metrics.insert(pipeline_id, epoch);
}
// When we are shutting_down, we need to avoid performing operations
// such as Paint that may crash because we have begun tearing down
// the rest of our resources.
@ -1427,6 +1439,38 @@ impl<Window: WindowMethods> IOCompositor<Window> {
self.webrender.render(self.frame_size);
});
// If there are pending paint metrics, we check if any of the painted epochs is
// one of the ones that the paint metrics recorder is expecting . In that case,
// we get the current time, inform the layout thread about it and remove the
// pending metric from the list.
if !self.pending_paint_metrics.is_empty() {
let paint_time = precise_time_ns() as f64;
let mut to_remove = Vec::new();
// For each pending paint metrics pipeline id
for (id, pending_epoch) in &self.pending_paint_metrics {
// we get the last painted frame id from webrender
if let Some(webrender_api::Epoch(epoch)) = self.webrender.current_epoch(id.to_webrender()) {
// and check if it is the one the layout thread is expecting,
let epoch = Epoch(epoch);
if *pending_epoch != epoch {
continue;
}
// in which case, we remove it from the list of pending metrics,
to_remove.push(id.clone());
if let Some(pipeline) = self.pipeline(*id) {
// and inform the layout thread with the measured paint time.
let msg = LayoutControlMsg::PaintMetric(epoch, paint_time);
if let Err(e) = pipeline.layout_chan.send(msg) {
warn!("Sending PaintMetric message to layout failed ({}).", e);
}
}
}
}
for id in to_remove.iter() {
self.pending_paint_metrics.remove(id);
}
}
let rv = match target {
CompositeTarget::Window => None,
CompositeTarget::WindowAndPng => {

View file

@ -7,6 +7,7 @@
use SendableFrameTree;
use compositor::CompositingReason;
use euclid::{Point2D, Size2D};
use gfx_traits::Epoch;
use ipc_channel::ipc::IpcSender;
use msg::constellation_msg::{Key, KeyModifiers, KeyState, PipelineId, TopLevelBrowsingContextId};
use net_traits::image::base::Image;
@ -143,6 +144,10 @@ pub enum Msg {
Dispatch(Box<Fn() + Send>),
/// Enter or exit fullscreen
SetFullscreenState(TopLevelBrowsingContextId, bool),
/// Indicates to the compositor that it needs to record the time when the frame with
/// the given ID (epoch) is painted and report it to the layout thread of the given
/// pipeline ID.
PendingPaintMetric(PipelineId, Epoch),
}
impl Debug for Msg {
@ -176,6 +181,7 @@ impl Debug for Msg {
Msg::NewScrollFrameReady(..) => write!(f, "NewScrollFrameReady"),
Msg::Dispatch(..) => write!(f, "Dispatch"),
Msg::SetFullscreenState(..) => write!(f, "SetFullscreenState"),
Msg::PendingPaintMetric(..) => write!(f, "PendingPaintMetric"),
}
}
}

View file

@ -1255,6 +1255,10 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
debug!("constellation got iframe size message");
self.handle_iframe_size_msg(iframe_sizes);
}
FromLayoutMsg::PendingPaintMetric(pipeline_id, epoch) => {
debug!("constellation got a pending paint metric message");
self.handle_pending_paint_metric(pipeline_id, epoch);
}
FromLayoutMsg::SetCursor(cursor) => {
self.handle_set_cursor_msg(cursor)
}
@ -1700,6 +1704,10 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
});
}
fn handle_pending_paint_metric(&self, pipeline_id: PipelineId, epoch: Epoch) {
self.compositor_proxy.send(ToCompositorMsg::PendingPaintMetric(pipeline_id, epoch))
}
fn handle_set_cursor_msg(&mut self, cursor: Cursor) {
self.compositor_proxy.send(ToCompositorMsg::SetCursor(cursor))
}

View file

@ -486,7 +486,9 @@ 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 paint_time_metrics = PaintTimeMetrics::new(self.id,
self.time_profiler_chan.clone(),
self.layout_to_constellation_chan.clone());
let layout_pair = STF::create(InitialScriptState {
id: self.id,
browsing_context_id: self.browsing_context_id,

View file

@ -18,7 +18,7 @@ use range::RangeIndex;
use std::sync::atomic::{ATOMIC_USIZE_INIT, AtomicUsize, Ordering};
/// A newtype struct for denoting the age of messages; prevents race conditions.
#[derive(PartialEq, Eq, Debug, Copy, Clone, PartialOrd, Ord, Deserialize, Serialize)]
#[derive(PartialEq, Eq, Debug, Copy, Clone, PartialOrd, Ord, Deserialize, Serialize, Hash)]
pub struct Epoch(pub u32);
impl Epoch {

View file

@ -674,6 +674,10 @@ impl LayoutThread {
Request::FromPipeline(LayoutControlMsg::ExitNow) => {
self.handle_request_helper(Msg::ExitNow, possibly_locked_rw_data)
},
Request::FromPipeline(LayoutControlMsg::PaintMetric(epoch, paint_time)) => {
self.paint_time_metrics.maybe_set_metric(epoch, paint_time);
true
},
Request::FromScript(msg) => {
self.handle_request_helper(msg, possibly_locked_rw_data)
},
@ -1079,10 +1083,10 @@ impl LayoutThread {
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);
// Observe notifications about rendered frames if needed right before
// sending the display list to WebRender in order to set time related
// Progressive Web Metrics.
self.paint_time_metrics.maybe_observe_paint_time(self, epoch, &display_list);
self.webrender_api.set_display_list(
self.webrender_document,

View file

@ -11,6 +11,10 @@ path = "lib.rs"
[dependencies]
gfx = {path = "../gfx"}
gfx_traits = {path = "../gfx_traits"}
ipc-channel = "0.8"
log = "0.3.5"
msg = {path = "../msg"}
profile_traits = {path = "../profile_traits"}
script_traits = {path = "../script_traits"}
servo_config = {path = "../config"}
time = "0.1.12"

View file

@ -3,15 +3,25 @@
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
extern crate gfx;
extern crate gfx_traits;
extern crate ipc_channel;
#[macro_use]
extern crate log;
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;
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::LayoutMsg;
use servo_config::opts;
use std::cell::Cell;
use std::cell::{Cell, RefCell};
use std::collections::HashMap;
pub trait ProfilerMetadataFactory {
fn new_metadata(&self) -> Option<TimerMetadata>;
@ -19,23 +29,25 @@ pub trait ProfilerMetadataFactory {
macro_rules! make_time_setter(
( $attr:ident, $func:ident, $category:ident, $label:expr ) => (
fn $func<T>(&self, profiler_metadata_factory: &T)
where T: ProfilerMetadataFactory {
fn $func(&self, profiler_metadata: Option<TimerMetadata>, paint_time: f64) {
if self.$attr.get().is_some() {
return;
}
let navigation_start = match self.navigation_start {
Some(time) => time,
None => {
println!("Trying to set metric before navigation start");
warn!("Trying to set metric before navigation start");
return;
}
};
let now = time::precise_time_ns() as f64;
let time = now - navigation_start;
let time = paint_time - navigation_start;
self.$attr.set(Some(time));
// Send the metric to the time profiler.
send_profile_data(ProfilerCategory::$category,
profiler_metadata_factory.new_metadata(),
profiler_metadata,
&self.time_profiler_chan,
time as u64, time as u64, 0, 0);
@ -48,20 +60,28 @@ macro_rules! make_time_setter(
);
pub struct PaintTimeMetrics {
pending_metrics: RefCell<HashMap<Epoch, (Option<TimerMetadata>, bool)>>,
navigation_start: Option<f64>,
first_paint: Cell<Option<f64>>,
first_contentful_paint: Cell<Option<f64>>,
pipeline_id: PipelineId,
time_profiler_chan: ProfilerChan,
constellation_chan: IpcSender<LayoutMsg>,
}
impl PaintTimeMetrics {
pub fn new(time_profiler_chan: ProfilerChan)
pub fn new(pipeline_id: PipelineId,
time_profiler_chan: ProfilerChan,
constellation_chan: IpcSender<LayoutMsg>)
-> PaintTimeMetrics {
PaintTimeMetrics {
pending_metrics: RefCell::new(HashMap::new()),
navigation_start: None,
first_paint: Cell::new(None),
first_contentful_paint: Cell::new(None),
time_profiler_chan: time_profiler_chan,
pipeline_id,
time_profiler_chan,
constellation_chan,
}
}
@ -76,39 +96,61 @@ impl PaintTimeMetrics {
TimeToFirstContentfulPaint,
"first-contentful-paint");
pub fn maybe_set_first_paint<T>(&self, profiler_metadata_factory: &T)
pub fn maybe_observe_paint_time<T>(&self,
profiler_metadata_factory: &T,
epoch: Epoch,
display_list: &DisplayList)
where T: ProfilerMetadataFactory {
{
if self.first_paint.get().is_some() {
return;
}
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;
}
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)
let mut is_contentful = false;
// Analyze the display list to figure out if this may be 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;
is_contentful = true;
break;
},
_ => (),
}
}
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
// frame with the given ID and will send the metric back to us.
let msg = LayoutMsg::PendingPaintMetric(self.pipeline_id, epoch);
if let Err(e) = self.constellation_chan.send(msg) {
warn!("Failed to send PendingPaintMetric {:?}", e);
}
}
pub fn maybe_set_metric(&mut 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() {
// If we already set all paint metrics or we have not set navigation start yet,
// we just bail out.
return;
}
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);
if pending_metric.1 {
self.set_first_contentful_paint(profiler_metadata, paint_time);
}
}
}
pub fn get_navigation_start(&self) -> Option<f64> {

View file

@ -1480,7 +1480,9 @@ 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()),
paint_time_metrics: PaintTimeMetrics::new(new_pipeline_id,
self.time_profiler_chan.clone(),
self.layout_to_constellation_chan.clone()),
});
// Pick a layout thread, any layout thread

View file

@ -22,7 +22,6 @@ 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"}
profile_traits = {path = "../profile_traits"}

View file

@ -124,6 +124,8 @@ pub enum LayoutControlMsg {
/// Requests the current load state of Web fonts. `true` is returned if fonts are still loading
/// and `false` is returned if all fonts have loaded.
GetWebFontLoadState(IpcSender<bool>),
/// Send the paint time for a specific epoch to the layout thread.
PaintMetric(Epoch, f64),
}
/// can be passed to `LoadUrl` to load a page with GET/POST

View file

@ -15,6 +15,7 @@ use WorkerScriptLoadOrigin;
use canvas_traits::canvas::CanvasMsg;
use devtools_traits::{ScriptToDevtoolsControlMsg, WorkerId};
use euclid::{Point2D, Size2D, TypedSize2D};
use gfx_traits::Epoch;
use ipc_channel::ipc::IpcSender;
use msg::constellation_msg::{BrowsingContextId, FrameType, PipelineId, TraversalDirection};
use msg::constellation_msg::{Key, KeyModifiers, KeyState};
@ -35,6 +36,9 @@ pub enum LayoutMsg {
ChangeRunningAnimationsState(PipelineId, AnimationState),
/// Inform the constellation of the size of the iframe's viewport.
IFrameSizes(Vec<(BrowsingContextId, TypedSize2D<f32, CSSPixel>)>),
/// Requests that the constellation inform the compositor that it needs to record
/// the time when the frame with the given ID (epoch) is painted.
PendingPaintMetric(PipelineId, Epoch),
/// Requests that the constellation inform the compositor of the a cursor change.
SetCursor(Cursor),
/// Notifies the constellation that the viewport has been constrained in some manner

View file

@ -12,6 +12,7 @@ doctest = false
[dependencies]
euclid = "0.15"
gfx = {path = "../../../components/gfx"}
gfx_traits = {path = "../../../components/gfx_traits"}
ipc-channel = "0.8"
metrics = {path = "../../../components/metrics"}
msg = {path = "../../../components/msg"}

View file

@ -4,6 +4,7 @@
extern crate euclid;
extern crate gfx;
extern crate gfx_traits;
extern crate ipc_channel;
extern crate metrics;
extern crate msg;

View file

@ -5,6 +5,7 @@
use euclid::Size2D;
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 msg::constellation_msg::{PipelineId, PipelineIndex, PipelineNamespaceId};
@ -22,57 +23,62 @@ impl ProfilerMetadataFactory for DummyProfilerMetadataFactory {
#[test]
fn test_paint_metrics_construction() {
let pipeline_id = PipelineId {
namespace_id: PipelineNamespaceId(1),
index: PipelineIndex(1),
};
let (sender, _) = ipc::channel().unwrap();
let profiler_chan = ProfilerChan(sender);
let paint_time_metrics = PaintTimeMetrics::new(profiler_chan);
let (layout_sender, _) = ipc::channel().unwrap();
let paint_time_metrics = PaintTimeMetrics::new(pipeline_id, profiler_chan, layout_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");
}
#[test]
fn test_first_paint_setter() {
fn test_common(display_list: &DisplayList, epoch: Epoch) -> PaintTimeMetrics {
let pipeline_id = PipelineId {
namespace_id: PipelineNamespaceId(1),
index: PipelineIndex(1),
};
let (sender, _) = ipc::channel().unwrap();
let profiler_chan = ProfilerChan(sender);
let mut paint_time_metrics = PaintTimeMetrics::new(profiler_chan);
let (layout_sender, _) = ipc::channel().unwrap();
let mut paint_time_metrics = PaintTimeMetrics::new(pipeline_id, profiler_chan, layout_sender);
let dummy_profiler_metadata_factory = DummyProfilerMetadataFactory {};
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_first_paint(&dummy_profiler_metadata_factory);
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");
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");
paint_time_metrics.maybe_set_first_paint(&dummy_profiler_metadata_factory);
paint_time_metrics
}
#[test]
fn test_first_paint_setter() {
let empty_display_list = DisplayList {
list: Vec::new()
};
let epoch = Epoch(0);
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");
}
#[test]
fn test_first_contentful_paint_setter() {
let (sender, _) = ipc::channel().unwrap();
let profiler_chan = ProfilerChan(sender);
let mut paint_time_metrics = PaintTimeMetrics::new(profiler_chan);
let dummy_profiler_metadata_factory = DummyProfilerMetadataFactory {};
let empty_display_list = DisplayList {
list: Vec::new()
};
// Should not set any metric until navigation start is set.
paint_time_metrics.maybe_set_first_contentful_paint(&dummy_profiler_metadata_factory,
&empty_display_list);
assert_eq!(paint_time_metrics.get_first_contentful_paint(), None, "first contentful paint is None");
// Should not set first contentful paint if no appropriate display item is present.
let navigation_start = time::precise_time_ns() as f64;
paint_time_metrics.set_navigation_start(navigation_start);
paint_time_metrics.maybe_set_first_contentful_paint(&dummy_profiler_metadata_factory,
&empty_display_list);
assert_eq!(paint_time_metrics.get_first_contentful_paint(), None, "first contentful paint is None");
let pipeline_id = PipelineId {
namespace_id: PipelineNamespaceId(1),
index: PipelineIndex(1),
@ -93,8 +99,10 @@ fn test_first_contentful_paint_setter() {
let display_list = DisplayList {
list: vec![image]
};
paint_time_metrics.maybe_set_first_contentful_paint(&dummy_profiler_metadata_factory,
&display_list);
let epoch = Epoch(0);
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_eq!(paint_time_metrics.get_first_paint(), None, "first paint is None");
assert!(paint_time_metrics.get_first_paint().is_some(), "first paint is set");
}