//! Opt-in counters and coarse timers for explaining CPU layout cost. //! //! Enable the `layout-diagnostics` feature. With it disabled, none of the //! instrumentation is compiled into Iris. The retained rig in //! `tests/layout_diagnostics.rs` is the ordinary entry point. //! //! Timers are inclusive: `update total` contains `full layout` or //! `incremental layout`, and `text render` contains shaping and glyph //! placement. They locate cost within one instrumented run and must not be //! added together. Use an uninstrumented build under `perf` for final CPU //! totals; counting every primitive and distinct widget deliberately perturbs //! the instrumented run. //! //! Call [`trace_widget`] before a frame to retain the ordered constraint, //! reuse, size, placement, and text events for one suspicious widget. The //! selection is a set and survives [`take`] until cleared. use crate::{Axis, LayoutLen, PxVec2, Size, UiRegion, WidgetId}; use std::{ cell::RefCell, collections::{HashMap, HashSet}, fmt::Write, time::Instant, }; #[derive(Clone, Copy)] pub(crate) enum Counter { Updates, DrawRequests, WidgetDraws, RegionNodeDraws, SizeReads, HintHits, HintMisses, ReuseAttempts, ReuseExact, ReuseMoved, ReuseDirty, ReuseWrongParent, ReuseRemapped, ReuseOutside, ReuseWrongLayer, ReuseWrongNode, QueuePops, DepthReads, LocalRedraws, SizeChanges, ReaderEdges, PrimitiveWrites, TextRenders, TextShapeHits, TextShapes, TextBreaks, GlyphPlacements, OutsidePinnedLen, OutsideFrame, OutsideRegion, } impl Counter { const COUNT: usize = Self::OutsideRegion as usize + 1; const NAMES: [&'static str; Self::COUNT] = [ "updates", "draw requests", "widget draws", "region-node draws", "draw-result size reads", "hint hits", "hint misses", "reuse attempts", "reuse exact", "reuse moved", "reuse: dirty", "reuse: wrong parent", "reuse remapped", "reuse: outside what it holds for", "reuse: another layer", "reuse: region-node choice changed", "redraw queue pops", "depth reads", "local redraws", "size changes", "reader edges", "primitive writes", "text renders", "text shape hits", "text shapes", "text line breaks", "glyph placements", "reuse outside: the length it was pinned to", "reuse outside: a frame length", "reuse outside: a region length", ]; } #[derive(Clone, Copy)] pub(crate) enum TimerKind { Update, FullLayout, IncrementalLayout, TextRender, TextShape, TextBreak, GlyphPlacement, } impl TimerKind { const COUNT: usize = Self::GlyphPlacement as usize + 1; const NAMES: [&'static str; Self::COUNT] = [ "update total", "full layout", "incremental layout", "text render", "text shape", "text line break", "glyph placement", ]; } #[derive(Clone)] pub struct Report { counters: [u64; Counter::COUNT], nanos: [u64; TimerKind::COUNT], distinct_widgets: usize, distinct_text_widgets: usize, hot_widgets: Vec, hot_text: Vec, traces: Vec, } impl Default for Report { fn default() -> Self { Self { counters: [0; Counter::COUNT], nanos: [0; TimerKind::COUNT], distinct_widgets: 0, distinct_text_widgets: 0, hot_widgets: Vec::new(), hot_text: Vec::new(), traces: Vec::new(), } } } impl Report { pub fn counters(&self) -> impl Iterator + '_ { Counter::NAMES.into_iter().zip(self.counters) } /// Inclusive elapsed time accumulated for each targeted operation. pub fn timings_ns(&self) -> impl Iterator + '_ { TimerKind::NAMES.into_iter().zip(self.nanos) } pub fn distinct_widgets(&self) -> usize { self.distinct_widgets } pub fn distinct_text_widgets(&self) -> usize { self.distinct_text_widgets } pub fn hot_widgets(&self) -> &[Callsite] { &self.hot_widgets } pub fn hot_text(&self) -> &[Callsite] { &self.hot_text } /// Ordered layout events for widgets selected with [`trace_widget`]. pub fn traces(&self) -> &[TraceEvent] { &self.traces } /// Formats nonzero totals divided by `frames`. pub fn per_frame(&self, frames: usize) -> String { let divisor = frames.max(1) as f64; let mut out = String::new(); for (name, value) in self.counters() { if value != 0 { let _ = writeln!(out, " {name:<27} {:>12.2}", value as f64 / divisor); } } if self.distinct_widgets != 0 { let _ = writeln!( out, " {:<27} {:>12}", "distinct widgets", self.distinct_widgets ); } if self.distinct_text_widgets != 0 { let _ = writeln!( out, " {:<27} {:>12}", "distinct text widgets", self.distinct_text_widgets ); } for (name, nanos) in self.timings_ns() { if nanos != 0 { let ms = nanos as f64 / divisor / 1_000_000.0; let _ = writeln!(out, " {name:<27} {ms:>12.3} ms"); } } if !self.hot_widgets.is_empty() { let _ = writeln!(out, " hottest widget draws:"); for callsite in &self.hot_widgets { let calls = callsite.calls as f64 / divisor; let _ = writeln!( out, " {calls:>9.2} {:?} {}", callsite.id, callsite.label ); } } if !self.hot_text.is_empty() { let _ = writeln!(out, " hottest text renders:"); for callsite in &self.hot_text { let calls = callsite.calls as f64 / divisor; let _ = writeln!( out, " {calls:>9.2} {:>3} widths {:?} {}", callsite.distinct_widths, callsite.id, callsite.label ); } } if !self.traces.is_empty() { let _ = writeln!(out, " targeted layout trace:"); for event in &self.traces { let _ = writeln!(out, " {event:?}"); } } out } } #[derive(Clone)] pub struct Callsite { pub id: WidgetId, pub label: String, pub calls: u64, pub distinct_widths: usize, } #[derive(Clone, Copy, Debug, PartialEq)] pub enum ReuseOutcome { Exact, Moved, Dirty, WrongParent, WrongLayer, Remapped, Outside, Undrawn, } /// One targeted layout event. Events are retained in execution order, making /// repeated constraint paths visible without logging every widget globally. #[derive(Clone, Copy, Debug, PartialEq)] pub enum TraceEvent { DrawRequest { id: WidgetId, parent: Option, region: UiRegion, pixel_size: PxVec2, region_node: bool, }, Reuse { id: WidgetId, outcome: ReuseOutcome, }, SizeReported { id: WidgetId, size: Size, }, RegionNode { id: WidgetId, parent: WidgetId, region: UiRegion, }, SizeRead { id: WidgetId, reader: WidgetId, size: Size, }, HintRead { id: WidgetId, reader: WidgetId, axis: Axis, hint: Option, }, TextRendered { id: WidgetId, width: Option, }, } #[derive(Default)] struct Calls { label: String, count: u64, widths: HashSet>, } #[derive(Default)] struct Current { report: Report, widgets: HashMap, text_widgets: HashMap, traced: HashSet, } thread_local! { static CURRENT: RefCell = RefCell::new(Current::default()); } pub(crate) fn bump(counter: Counter) { CURRENT.with_borrow_mut(|current| current.report.counters[counter as usize] += 1); } pub(crate) fn draw_widget(id: WidgetId, label: &str) { CURRENT.with_borrow_mut(|current| { let calls = current.widgets.entry(id).or_default(); if calls.label.is_empty() { calls.label = label.to_owned(); } calls.count += 1; }); } /// Adds a widget to the targeted trace set. Selection survives [`take`] /// until explicitly removed or cleared. pub fn trace_widget(id: impl Into) { CURRENT.with_borrow_mut(|current| { current.traced.insert(id.into()); }); } pub fn untrace_widget(id: impl Into) { CURRENT.with_borrow_mut(|current| { current.traced.remove(&id.into()); }); } pub fn clear_traced_widgets() { CURRENT.with_borrow_mut(|current| current.traced.clear()); } fn trace(id: WidgetId, event: TraceEvent) { CURRENT.with_borrow_mut(|current| { if current.traced.contains(&id) { current.report.traces.push(event); } }); } pub(crate) fn draw_request( id: WidgetId, parent: Option, region: UiRegion, pixel_size: PxVec2, region_node: bool, ) { trace( id, TraceEvent::DrawRequest { id, parent, region, pixel_size, region_node, }, ); } pub(crate) fn reuse(id: WidgetId, outcome: ReuseOutcome) { trace(id, TraceEvent::Reuse { id, outcome }); } pub(crate) fn size_reported(id: WidgetId, size: Size) { trace(id, TraceEvent::SizeReported { id, size }); } pub(crate) fn region_node(id: WidgetId, parent: WidgetId, region: UiRegion) { trace(id, TraceEvent::RegionNode { id, parent, region }); } pub(crate) fn size_read(id: WidgetId, reader: WidgetId, size: Size) { trace(id, TraceEvent::SizeRead { id, reader, size }); } pub(crate) fn hint_read(id: WidgetId, reader: WidgetId, axis: Axis, hint: Option) { trace( id, TraceEvent::HintRead { id, reader, axis, hint, }, ); } pub(crate) fn render_text(id: WidgetId, label: &str, width: Option) { CURRENT.with_borrow_mut(|current| { let calls = current.text_widgets.entry(id).or_default(); if calls.label.is_empty() { calls.label = label.to_owned(); } calls.count += 1; calls.widths.insert(width.map(f32::to_bits)); if current.traced.contains(&id) { current .report .traces .push(TraceEvent::TextRendered { id, width }); } }); } pub(crate) struct Timer { kind: TimerKind, start: Instant, } pub(crate) fn timer(kind: TimerKind) -> Timer { Timer { kind, start: Instant::now(), } } impl Drop for Timer { fn drop(&mut self) { let nanos = self.start.elapsed().as_nanos().min(u64::MAX as u128) as u64; CURRENT.with_borrow_mut(|current| current.report.nanos[self.kind as usize] += nanos); } } /// Takes all diagnostics accumulated on this thread and resets them. pub fn take() -> Report { CURRENT.with_borrow_mut(|current| { current.report.distinct_widgets = current.widgets.len(); current.report.distinct_text_widgets = current.text_widgets.len(); current.report.hot_widgets = hottest(¤t.widgets); current.report.hot_text = hottest(¤t.text_widgets); let report = std::mem::take(&mut current.report); current.widgets.clear(); current.text_widgets.clear(); report }) } fn hottest(calls: &HashMap) -> Vec { let mut calls: Vec<_> = calls .iter() .map(|(&id, calls)| Callsite { id, label: calls.label.clone(), calls: calls.count, distinct_widths: calls.widths.len(), }) .collect(); calls.sort_by(|a, b| b.calls.cmp(&a.calls).then_with(|| a.label.cmp(&b.label))); calls.truncate(8); calls } #[cfg(test)] mod tests { use super::*; #[test] fn taking_a_report_resets_its_counters() { let _ = take(); bump(Counter::Updates); bump(Counter::Updates); let report = take(); assert_eq!(report.counters().next(), Some(("updates", 2))); assert!(take().counters().all(|(_, count)| count == 0)); } }