Auto merge of #16379 - bholley:quieter_stats, r=SimonSapin

Limit traversal statistics dumps to subtrees of 50 or more elements and add more values.

On Gecko, we get tons of console spam from 1-element traversals if we don't do this.

<!-- Reviewable:start -->
---
This change is [<img src="https://reviewable.io/review_button.svg" height="34" align="absmiddle" alt="Reviewable"/>](https://reviewable.io/reviews/servo/servo/16379)
<!-- Reviewable:end -->
This commit is contained in:
bors-servo 2017-04-13 01:44:12 -05:00 committed by GitHub
commit b514168469
5 changed files with 95 additions and 15 deletions

View file

@ -171,6 +171,16 @@ pub struct TraversalStatistics {
pub elements_matched: u32, pub elements_matched: u32,
/// The number of cache hits from the StyleSharingCache. /// The number of cache hits from the StyleSharingCache.
pub styles_shared: u32, pub styles_shared: u32,
/// The number of selectors in the stylist.
pub selectors: u32,
/// The number of revalidation selectors.
pub revalidation_selectors: u32,
/// The number of state/attr dependencies in the dependency set.
pub dependency_selectors: u32,
/// The number of declarations in the stylist.
pub declarations: u32,
/// The number of times the stylist was rebuilt.
pub stylist_rebuilds: u32,
/// Time spent in the traversal, in milliseconds. /// Time spent in the traversal, in milliseconds.
pub traversal_time_ms: f64, pub traversal_time_ms: f64,
/// Whether this was a parallel traversal. /// Whether this was a parallel traversal.
@ -183,11 +193,21 @@ impl<'a> Add for &'a TraversalStatistics {
fn add(self, other: Self) -> TraversalStatistics { fn add(self, other: Self) -> TraversalStatistics {
debug_assert!(self.traversal_time_ms == 0.0 && other.traversal_time_ms == 0.0, debug_assert!(self.traversal_time_ms == 0.0 && other.traversal_time_ms == 0.0,
"traversal_time_ms should be set at the end by the caller"); "traversal_time_ms should be set at the end by the caller");
debug_assert!(self.selectors == 0, "set at the end");
debug_assert!(self.revalidation_selectors == 0, "set at the end");
debug_assert!(self.dependency_selectors == 0, "set at the end");
debug_assert!(self.declarations == 0, "set at the end");
debug_assert!(self.stylist_rebuilds == 0, "set at the end");
TraversalStatistics { TraversalStatistics {
elements_traversed: self.elements_traversed + other.elements_traversed, elements_traversed: self.elements_traversed + other.elements_traversed,
elements_styled: self.elements_styled + other.elements_styled, elements_styled: self.elements_styled + other.elements_styled,
elements_matched: self.elements_matched + other.elements_matched, elements_matched: self.elements_matched + other.elements_matched,
styles_shared: self.styles_shared + other.styles_shared, styles_shared: self.styles_shared + other.styles_shared,
selectors: 0,
revalidation_selectors: 0,
dependency_selectors: 0,
declarations: 0,
stylist_rebuilds: 0,
traversal_time_ms: 0.0, traversal_time_ms: 0.0,
is_parallel: None, is_parallel: None,
} }
@ -209,6 +229,11 @@ impl fmt::Display for TraversalStatistics {
try!(writeln!(f, "[PERF],elements_styled,{}", self.elements_styled)); try!(writeln!(f, "[PERF],elements_styled,{}", self.elements_styled));
try!(writeln!(f, "[PERF],elements_matched,{}", self.elements_matched)); try!(writeln!(f, "[PERF],elements_matched,{}", self.elements_matched));
try!(writeln!(f, "[PERF],styles_shared,{}", self.styles_shared)); try!(writeln!(f, "[PERF],styles_shared,{}", self.styles_shared));
try!(writeln!(f, "[PERF],selectors,{}", self.selectors));
try!(writeln!(f, "[PERF],revalidation_selectors,{}", self.revalidation_selectors));
try!(writeln!(f, "[PERF],dependency_selectors,{}", self.dependency_selectors));
try!(writeln!(f, "[PERF],declarations,{}", self.declarations));
try!(writeln!(f, "[PERF],stylist_rebuilds,{}", self.stylist_rebuilds));
try!(writeln!(f, "[PERF],traversal_time_ms,{}", self.traversal_time_ms)); try!(writeln!(f, "[PERF],traversal_time_ms,{}", self.traversal_time_ms));
writeln!(f, "[PERF] perf block end") writeln!(f, "[PERF] perf block end")
} }
@ -222,6 +247,17 @@ impl TraversalStatistics {
{ {
self.is_parallel = Some(traversal.is_parallel()); self.is_parallel = Some(traversal.is_parallel());
self.traversal_time_ms = (time::precise_time_s() - start) * 1000.0; self.traversal_time_ms = (time::precise_time_s() - start) * 1000.0;
self.selectors = traversal.shared_context().stylist.num_selectors() as u32;
self.revalidation_selectors = traversal.shared_context().stylist.num_revalidation_selectors() as u32;
self.dependency_selectors = traversal.shared_context().stylist.num_dependencies() as u32;
self.declarations = traversal.shared_context().stylist.num_declarations() as u32;
self.stylist_rebuilds = traversal.shared_context().stylist.num_rebuilds() as u32;
}
/// Returns whether this traversal is 'large' in order to avoid console spam
/// from lots of tiny traversals.
pub fn is_large_traversal(&self) -> bool {
self.elements_traversed >= 50
} }
} }

View file

@ -86,7 +86,9 @@ pub fn traverse_dom<E, D>(traversal: &D,
} }
}); });
aggregate.finish(traversal, start_time.unwrap()); aggregate.finish(traversal, start_time.unwrap());
println!("{}", aggregate); if aggregate.is_large_traversal() {
println!("{}", aggregate);
}
} }
} }

View file

@ -60,6 +60,11 @@ impl fmt::Debug for PropertyDeclarationBlock {
} }
impl PropertyDeclarationBlock { impl PropertyDeclarationBlock {
/// Returns the number of declarations in the block.
pub fn len(&self) -> usize {
self.declarations.len()
}
/// Create an empty block /// Create an empty block
pub fn new() -> Self { pub fn new() -> Self {
PropertyDeclarationBlock { PropertyDeclarationBlock {

View file

@ -64,6 +64,8 @@ pub fn traverse_dom<E, D>(traversal: &D,
if dump_stats { if dump_stats {
let tlsc = tlc.borrow_mut(); let tlsc = tlc.borrow_mut();
tlsc.statistics.finish(traversal, start_time.unwrap()); tlsc.statistics.finish(traversal, start_time.unwrap());
println!("{}", tlsc.statistics); if tlsc.statistics.is_large_traversal() {
println!("{}", tlsc.statistics);
}
} }
} }

View file

@ -109,13 +109,22 @@ pub struct Stylist {
rules_source_order: usize, rules_source_order: usize,
/// Selector dependencies used to compute restyle hints. /// Selector dependencies used to compute restyle hints.
state_deps: DependencySet, dependencies: DependencySet,
/// Selectors that require explicit cache revalidation (i.e. which depend /// Selectors that require explicit cache revalidation (i.e. which depend
/// on state that is not otherwise visible to the cache, like attributes or /// on state that is not otherwise visible to the cache, like attributes or
/// tree-structural state like child index and pseudos). /// tree-structural state like child index and pseudos).
#[cfg_attr(feature = "servo", ignore_heap_size_of = "Arc")] #[cfg_attr(feature = "servo", ignore_heap_size_of = "Arc")]
selectors_for_cache_revalidation: Vec<Selector<SelectorImpl>>, selectors_for_cache_revalidation: Vec<Selector<SelectorImpl>>,
/// The total number of selectors.
num_selectors: usize,
/// The total number of declarations.
num_declarations: usize,
/// The total number of times the stylist has been rebuilt.
num_rebuilds: usize,
} }
/// This struct holds data which user of Stylist may want to extract /// This struct holds data which user of Stylist may want to extract
@ -165,9 +174,11 @@ impl Stylist {
precomputed_pseudo_element_decls: Default::default(), precomputed_pseudo_element_decls: Default::default(),
rules_source_order: 0, rules_source_order: 0,
rule_tree: RuleTree::new(), rule_tree: RuleTree::new(),
state_deps: DependencySet::new(), dependencies: DependencySet::new(),
selectors_for_cache_revalidation: vec![], selectors_for_cache_revalidation: vec![],
num_selectors: 0,
num_declarations: 0,
num_rebuilds: 0,
}; };
SelectorImpl::each_eagerly_cascaded_pseudo_element(|pseudo| { SelectorImpl::each_eagerly_cascaded_pseudo_element(|pseudo| {
@ -179,6 +190,31 @@ impl Stylist {
stylist stylist
} }
/// Returns the number of selectors.
pub fn num_selectors(&self) -> usize {
self.num_selectors
}
/// Returns the number of declarations.
pub fn num_declarations(&self) -> usize {
self.num_declarations
}
/// Returns the number of times the stylist has been rebuilt.
pub fn num_rebuilds(&self) -> usize {
self.num_rebuilds
}
/// Returns the number of dependencies in the DependencySet.
pub fn num_dependencies(&self) -> usize {
self.dependencies.len()
}
/// Returns the number of revalidation_selectors.
pub fn num_revalidation_selectors(&self) -> usize {
self.selectors_for_cache_revalidation.len()
}
/// Update the stylist for the given document stylesheets, and optionally /// Update the stylist for the given document stylesheets, and optionally
/// with a set of user agent stylesheets. /// with a set of user agent stylesheets.
/// ///
@ -194,6 +230,7 @@ impl Stylist {
if !(self.is_device_dirty || stylesheets_changed) { if !(self.is_device_dirty || stylesheets_changed) {
return false; return false;
} }
self.num_rebuilds += 1;
let cascaded_rule = ViewportRule { let cascaded_rule = ViewportRule {
declarations: viewport::Cascade::from_stylesheets( declarations: viewport::Cascade::from_stylesheets(
@ -218,10 +255,11 @@ impl Stylist {
self.precomputed_pseudo_element_decls = Default::default(); self.precomputed_pseudo_element_decls = Default::default();
self.rules_source_order = 0; self.rules_source_order = 0;
self.state_deps.clear(); self.dependencies.clear();
self.animations.clear(); self.animations.clear();
self.selectors_for_cache_revalidation.clear(); self.selectors_for_cache_revalidation.clear();
self.num_selectors = 0;
self.num_declarations = 0;
extra_data.clear_font_faces(); extra_data.clear_font_faces();
@ -240,12 +278,6 @@ impl Stylist {
self.add_stylesheet(stylesheet, guards.author, extra_data); self.add_stylesheet(stylesheet, guards.author, extra_data);
} }
debug!("Stylist stats:");
debug!(" - Got {} selectors for cache revalidation",
self.selectors_for_cache_revalidation.len());
debug!(" - Got {} deps for style-hint calculation",
self.state_deps.len());
SelectorImpl::each_precomputed_pseudo_element(|pseudo| { SelectorImpl::each_precomputed_pseudo_element(|pseudo| {
if let Some(map) = self.pseudos_map.remove(&pseudo) { if let Some(map) = self.pseudos_map.remove(&pseudo) {
let declarations = let declarations =
@ -273,7 +305,10 @@ impl Stylist {
match *rule { match *rule {
CssRule::Style(ref locked) => { CssRule::Style(ref locked) => {
let style_rule = locked.read_with(&guard); let style_rule = locked.read_with(&guard);
self.num_declarations += style_rule.block.read_with(&guard).len();
for selector in &style_rule.selectors.0 { for selector in &style_rule.selectors.0 {
self.num_selectors += 1;
let map = if let Some(ref pseudo) = selector.pseudo_element { let map = if let Some(ref pseudo) = selector.pseudo_element {
self.pseudos_map self.pseudos_map
.entry(pseudo.clone()) .entry(pseudo.clone())
@ -294,7 +329,7 @@ impl Stylist {
for selector in &style_rule.selectors.0 { for selector in &style_rule.selectors.0 {
let needs_cache_revalidation = let needs_cache_revalidation =
self.state_deps.note_selector(&selector.complex_selector); self.dependencies.note_selector(&selector.complex_selector);
if needs_cache_revalidation { if needs_cache_revalidation {
self.selectors_for_cache_revalidation.push(selector.clone()); self.selectors_for_cache_revalidation.push(selector.clone());
} }
@ -800,7 +835,7 @@ impl Stylist {
-> RestyleHint -> RestyleHint
where E: TElement, where E: TElement,
{ {
self.state_deps.compute_hint(element, snapshot) self.dependencies.compute_hint(element, snapshot)
} }
} }