fix time measure

Cargo.lock

@@ -1153,6 +1153,11 @@ dependencies = [
  "pkg-config 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)",
 ]
 
+[[package]]
+name = "histogram"
+version = "0.6.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+
 [[package]]
 name = "html5ever"
 version = "0.22.0"
@@ -1427,6 +1432,7 @@ dependencies = [
  "fnv 1.0.5 (registry+https://github.com/rust-lang/crates.io-index)",
  "gfx 0.0.1",
  "gfx_traits 0.0.1",
+ "histogram 0.6.8 (registry+https://github.com/rust-lang/crates.io-index)",
  "html5ever 0.22.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "ipc-channel 0.9.0 (registry+https://github.com/rust-lang/crates.io-index)",
  "layout 0.0.1",
@@ -3796,6 +3802,7 @@ dependencies = [
 "checksum harfbuzz-sys 0.1.15 (registry+https://github.com/rust-lang/crates.io-index)" = "52aa65c5649a0a2f1b27ab30093b3cc84681e17ddb552267e21948c5a6fa6b05"
 "checksum heartbeats-simple 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "9ad003ce233955e9d95f2c69cde84e68302ba9ba4a673d351c9bff93c738aadc"
 "checksum heartbeats-simple-sys 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)" = "e1a408c0011427cc0e0049f7861c70377819aedfc006e8c901b1c70fd98fb1a4"
+"checksum histogram 0.6.8 (registry+https://github.com/rust-lang/crates.io-index)" = "1bdcec4094c1ca961b685384ea7af76af5718230b3f34657d1a71fd2dcf4cc9d"
 "checksum html5ever 0.22.0 (registry+https://github.com/rust-lang/crates.io-index)" = "e579ac8647178ab915d400d7d22938bda5cd351c6c62e1c294d56884ccfc75fe"
 "checksum httparse 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "a6e7a63e511f9edffbab707141fbb8707d1a3098615fb2adbd5769cdfcc9b17d"
 "checksum hyper 0.10.13 (registry+https://github.com/rust-lang/crates.io-index)" = "368cb56b2740ebf4230520e2b90ebb0461e69034d85d1945febd9b3971426db2"

components/layout_thread/Cargo.toml

@@ -19,6 +19,7 @@ euclid = "0.17"
 fnv = "1.0"
 gfx = {path = "../gfx"}
 gfx_traits = {path = "../gfx_traits"}
+histogram = "0.6.8"
 html5ever = "0.22"
 ipc-channel = "0.9"
 layout = {path = "../layout"}

components/layout_thread/lib.rs

@@ -13,6 +13,7 @@ extern crate euclid;
 extern crate fnv;
 extern crate gfx;
 extern crate gfx_traits;
+extern crate histogram;
 #[macro_use]
 extern crate html5ever;
 extern crate ipc_channel;
@@ -61,6 +62,7 @@ use gfx::font;
 use gfx::font_cache_thread::FontCacheThread;
 use gfx::font_context;
 use gfx_traits::{Epoch, node_id_from_scroll_id};
+use histogram::Histogram;
 use ipc_channel::ipc::{self, IpcReceiver, IpcSender};
 use ipc_channel::router::ROUTER;
 use layout::animation;
@@ -263,7 +265,7 @@ pub struct LayoutThread {
     paint_time_metrics: PaintTimeMetrics,
 
     /// The time a layout query has waited before serviced by layout thread.
-    layout_query_timestamp: u64,
+    layout_query_waiting_time: Histogram,
 }
 
 impl LayoutThreadFactory for LayoutThread {
@@ -551,7 +553,7 @@ impl LayoutThread {
                 },
             layout_threads: layout_threads,
             paint_time_metrics: paint_time_metrics,
-            layout_query_timestamp: 0u64,
+            layout_query_waiting_time: Histogram::new(),
         }
     }
 
@@ -869,9 +871,16 @@ impl LayoutThread {
         // Drop the root flow explicitly to avoid holding style data, such as
         // rule nodes.  The `Stylist` checks when it is dropped that all rule
         // nodes have been GCed, so we want drop anyone who holds them first.
-        let now = std_time::precise_time_ns();
+        let waiting_time_min = self.layout_query_waiting_time.minimum().unwrap_or(0);
-        let waiting_time = now - self.layout_query_timestamp;
+        let waiting_time_max = self.layout_query_waiting_time.maximum().unwrap_or(0);
-        debug!("layout: query has been waited: {}", waiting_time);
+        let waiting_time_mean = self.layout_query_waiting_time.mean().unwrap_or(0);
+        let waiting_time_stddev = self.layout_query_waiting_time.stddev().unwrap_or(0);
+        debug!("layout: query waiting time: min: {}, max: {}, mean: {}, standard_deviation: {}",
+               waiting_time_min,
+               waiting_time_max,
+               waiting_time_mean,
+               waiting_time_stddev);
+
         self.root_flow.borrow_mut().take();
         // Drop the rayon threadpool if present.
         let _ = self.parallel_traversal.take();
@@ -1080,9 +1089,6 @@ impl LayoutThread {
     fn handle_reflow<'a, 'b>(&mut self,
                              data: &mut ScriptReflowResult,
                              possibly_locked_rw_data: &mut RwData<'a, 'b>) {
-        // Set layout query timestamp
-        data.reflow_goal.set_timestamp();
-
         let document = unsafe { ServoLayoutNode::new(&data.document) };
         let document = document.as_document().unwrap();
 
@@ -1095,9 +1101,14 @@ impl LayoutThread {
 
         let mut rw_data = possibly_locked_rw_data.lock();
 
+        // Record the time that layout query has been waited.
+        let now = std_time::precise_time_ns();
+        if let ReflowGoal::LayoutQuery(_, timestamp) = data.reflow_goal {
+            self.layout_query_waiting_time.increment(now - timestamp).expect("layout: wrong layout query timestamp");
+        };
+
         let element = match document.root_element() {
             None => {
-                self.layout_query_timestamp = data.reflow_goal.timestamp().expect("Not a QueryMsg");
                 // Since we cannot compute anything, give spec-required placeholders.
                 debug!("layout: No root node: bailing");
                 match data.reflow_goal {

components/script/dom/window.rs

@@ -1375,7 +1375,7 @@ impl Window {
     }
 
     pub fn layout_reflow(&self, query_msg: QueryMsg) -> bool {
-        self.reflow(ReflowGoal::LayoutQuery(query_msg, 0u64), ReflowReason::Query)
+        self.reflow(ReflowGoal::LayoutQuery(query_msg, time::precise_time_ns()), ReflowReason::Query)
     }
 
     pub fn layout(&self) -> &LayoutRPC {

components/script_layout_interface/lib.rs

@@ -33,7 +33,6 @@ extern crate servo_arc;
 extern crate servo_atoms;
 extern crate servo_url;
 extern crate style;
-extern crate time;
 extern crate webrender_api;
 
 pub mod message;

components/script_layout_interface/message.rs

@@ -24,7 +24,6 @@ use style::context::QuirksMode;
 use style::properties::PropertyId;
 use style::selector_parser::PseudoElement;
 use style::stylesheets::Stylesheet;
-use time;
 
 /// Asynchronous messages that script can send to layout.
 pub enum Msg {
@@ -172,26 +171,6 @@ impl ReflowGoal {
             },
         }
     }
-
-    /// Set the timestamp of query message.
-    pub fn set_timestamp(&mut self) {
-       match *self {
-           ReflowGoal::LayoutQuery(_, ref mut timestamp) => {
-               *timestamp = time::precise_time_ns();
-           },
-           _ => (),
-       }
-    }
-
-    /// Get the query timestamp.
-    pub fn timestamp(&self) -> Option<u64> {
-        match *self {
-            ReflowGoal::LayoutQuery(_, ref timestamp) => {
-                Some(*timestamp)
-            },
-            _ => None,
-        }
-    }
 }
 
 /// Information needed for a reflow.