ai-app/iris/src/diagnostics.rs

//! The trace toggle for the `iris::input`/`iris::frame` diagnostics (Iris's
//! 2026-09-07 request: "add another button to copy input event info ...
//! instrument a lot of the code with timings"), and the one place both
//! call sites' `iris::frame` line is written from.
//!
//! **Why a crate-level flag instead of `log::log_enabled!`/
//! `log::set_max_level`**: the app already installs its logger at
//! `LevelFilter::Debug` (`iris/android-app/src/lib.rs`'s `JNI_OnLoad`), so
//! a `log::Level::Debug` line reaches `client_core::log_ring`'s ring
//! regardless of what this instrument would prefer -- `RingLogger::enabled`
//! is unconditionally `true` by design (its own doc: "the ring wants
//! everything"). So the level alone cannot give these two targets a
//! default-off switch; the gate has to live on this side, checked before
//! `log::debug!` is even reached.
//!
//! **Why default off matters**: the ring is 2000 lines / 256 KiB
//! (`client_core::log_ring::DEFAULT_MAX_LINES`/`DEFAULT_MAX_BYTES`), and a
//! 120Hz session logging both a line per touch sample and a line per frame
//! fills that in seconds -- so a caller turns this on only for the length
//! of whatever is being investigated, and the report says so at its top
//! (a caller's job; see `iris::diagnostics::trace_enabled` used at the top
//! of whatever builds the report).
//!
//! **Not yet wired to a control**: the Diagnostics pane that would hold the
//! switch is in `iris/android-app/src/bench_client.rs`, which another agent
//! has open at the same time this was written. `set_trace` is the whole
//! surface a button needs; wiring one is a follow-up.
use std::sync::atomic::{AtomicBool, Ordering};
use std::time::{Duration, Instant};

use iris_core::UiRenderState;

static TRACE: AtomicBool = AtomicBool::new(false);

/// Turns the `iris::input`/`iris::frame` `debug!` lines on or off. Off by
/// default -- see the module doc for why turning the level on alone would
/// not do it.
pub fn set_trace(on: bool) {
    TRACE.store(on, Ordering::Relaxed);
}

/// Whether the `iris::input`/`iris::frame` lines are enabled right now --
/// what a report's header reads before deciding what to say about the
/// lines it does or doesn't hold (UI_RULES.md: "design the unknown state
/// first").
pub fn trace_enabled() -> bool {
    TRACE.load(Ordering::Relaxed)
}

/// One `iris::frame` line, called once per frame from each backend's own
/// frame function -- `android::view::IrisViewPeer::render`,
/// `default::DefaultApp::window_event`'s `RedrawRequested` arm, and
/// `harness::Harness::frame` -- after the draw (or, on the harness, where a
/// draw would be; `draw` is `Duration::ZERO` there since nothing is
/// actually submitted to a GPU).
///
/// `render.update(...)` must already have run this frame: this reads back
/// what it recorded (`UiRenderState::last_layout_duration`/
/// `last_redraw_kind`/`frame_number`) rather than timing anything itself,
/// so a caller's own measurement of the phase around `update()` and around
/// its own draw call are the only two `Instant` pairs in the whole path --
/// see each call site's own comment for why it is not restructured to fit
/// this instead.
pub fn log_frame(render: &UiRenderState, now: Instant, draw: Duration, animating: bool) {
    if !trace_enabled() {
        return;
    }
    let since_input = render
        .time_since_input(now)
        .map(|d| format!("{}ms", d.as_millis()))
        .unwrap_or_else(|| "none".to_string());
    log::debug!(
        target: "iris::frame",
        "iris frame: n={} now={}ms since_input={since_input} layout={:?} draw={:?} \
         redraw={:?} primitives={} animating={animating}",
        render.frame_number(),
        now.duration_since(render.epoch()).as_millis(),
        render.last_layout_duration(),
        draw,
        render.last_redraw_kind(),
        render.active_primitive_count(),
    );
}