iris/core/src/layout_diagnostics.rs

//! 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, Len, 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,
    RetainedSizeHits,
    ReuseAttempts,
    ReuseExact,
    ReuseMoved,
    ReuseDirty,
    ReuseWrongParent,
    ReuseRemapped,
    ReuseOutside,
    ReuseWrongLayer,
    ReuseWrongNode,
    PlaceRedraws,
    QueuePops,
    DepthReads,
    LocalRedraws,
    SizeChanges,
    ReaderEdges,
    PrimitiveWrites,
    TextRenders,
    TextShapeHits,
    TextShapes,
    TextBreaks,
    GlyphPlacements,
}

impl Counter {
    const COUNT: usize = Self::GlyphPlacements 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",
        "retained size hits",
        "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",
        "placed by redrawing",
        "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",
    ];
}

#[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<Callsite>,
    hot_text: Vec<Callsite>,
    traces: Vec<TraceEvent>,
}

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<Item = (&'static str, u64)> + '_ {
        Counter::NAMES.into_iter().zip(self.counters)
    }

    /// Inclusive elapsed time accumulated for each targeted operation.
    pub fn timings_ns(&self) -> impl Iterator<Item = (&'static str, u64)> + '_ {
        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<WidgetId>,
        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<Len>,
    },
    TextRendered {
        id: WidgetId,
        width: Option<f32>,
    },
}

#[derive(Default)]
struct Calls {
    label: String,
    count: u64,
    widths: HashSet<Option<u32>>,
}

#[derive(Default)]
struct Current {
    report: Report,
    widgets: HashMap<WidgetId, Calls>,
    text_widgets: HashMap<WidgetId, Calls>,
    traced: HashSet<WidgetId>,
}

thread_local! {
    static CURRENT: RefCell<Current> = 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<WidgetId>) {
    CURRENT.with_borrow_mut(|current| {
        current.traced.insert(id.into());
    });
}

pub fn untrace_widget(id: impl Into<WidgetId>) {
    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<WidgetId>,
    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<Len>) {
    trace(
        id,
        TraceEvent::HintRead {
            id,
            reader,
            axis,
            hint,
        },
    );
}

pub(crate) fn render_text(id: WidgetId, label: &str, width: Option<f32>) {
    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(&current.widgets);
        current.report.hot_text = hottest(&current.text_widgets);
        let report = std::mem::take(&mut current.report);
        current.widgets.clear();
        current.text_widgets.clear();
        report
    })
}

fn hottest(calls: &HashMap<WidgetId, Calls>) -> Vec<Callsite> {
    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));
    }
}