//! P0's iris half (docs/RUST.md's P0 box, docs/AGENTS.md's "The rigs"): //! the same fixture, scroll loop and streaming phase the Compose `bench` //! build type's `BenchRun.kt`/`BenchFixture.kt` drive, run here against //! `transcript-ui`'s real screen with no server -- a frame-time comparison //! that measures the renderer rather than the data or the network. //! //! **Reuses `transcript_client.rs`'s shape** (folded items, the same //! `TranscriptScreen::apply` incremental update on every event) with the //! network half replaced by the checked-in fixture. Reading that fixture //! and folding it into a screen is **`transcript-fixture`'s** job, not //! this file's -- the same crate the headless harness and the //! phone-shaped desktop window open, so all three measure one screen //! (AGENTS.md's sharing rule; moved out of here 2026-09-07). The tail is //! replayed one at a time through `fold_event` -- the same fold path a //! live SSE reply arrives on -- by the "Run benchmark" control below. //! Streaming through `apply` rather than a full rebuild per event is what //! this file exists to measure -- see docs/RUST.md's P0 box for the //! before/after report. use crate::android::bench_jni::PlatformHandle; use crate::client::transcript_fold::{TranscriptItem, fold_event}; use android_view::jni::{JavaVM, objects::GlobalRef}; use event_model::SeqEvent; use iris::android::{AndroidAppState, AndroidRsc, AndroidUiState, HasAndroidUiState}; use iris::prelude::*; use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant}; /// RUST.md's "Benchmark v2" spec, written once so both apps' bench clients /// implement the identical four phases -- see that box before changing any /// constant here, since a mismatch would make the two reports stop /// measuring the same thing while still looking like they do. const STREAM_EVENTS_PER_SEC: u64 = 20; const STREAM_SECONDS: u64 = 20; /// Kept only so this phase's own label text still reads "scroll: 6 cycles /// (24 swipes, legacy tween)" the way `BenchRun.kt`'s v2 report does -- /// `docs/bench/compose-phone-v2-2026-09-06.md`'s own report shows this /// exact line even though the swipe loop it names no longer runs there /// either (the fling phase replaced it); nothing here drives an actual /// swipe with these any more. const LEGACY_CYCLES: usize = 6; /// Fling phase (v2): a real fling through `Scroll::fling`, not a tween -- /// Iris's ask was that it "travel way faster" than the v1 swipe, and a /// tween can never exceed the distance/time it is given while a real /// fling decays from an initial velocity the way a finger flick does. /// 12,000 px/s matches `BenchRun.kt`'s own constant exactly. const FLING_VELOCITY_PX_S: f32 = 12_000.0; const FLING_COUNT: usize = 8; const FLING_SETTLE_CAP_MS: u64 = 3_000; const FLING_PAUSE_MS: u64 = 300; /// Type phase (v2): long, multisyllabic words so the composer actually /// wraps and the transcript above it is pushed upward, typed and deleted /// one character per `TYPE_CHAR_MS`. Exactly `BenchRun.TYPE_TEXT` -- /// verified 600 characters by `type_text_is_exactly_600_characters` below. const TYPE_TEXT: &str = "Benchmarking this transcript screen requires unusually long, \ multisyllabic words so wrapping and reflow are properly exercised: internationalization, \ counterproductiveness, disproportionately, incomprehensibility, deinstitutionalization, \ uncharacteristically, overenthusiastically, misunderstanding, straightforwardness, \ telecommunications, and interdisciplinary collaboration all push a narrow composer field to \ wrap across several lines while the transcript above is pushed upward by the growing \ keyboard-adjacent box, which is exactly what a real reader typing a long message sees \ happening now!!!"; const TYPE_CHAR_MS: u64 = 50; /// Keyboard phase (v2): five show/hide cycles, a second apart, matching /// `BenchRun.kt`'s `KEYBOARD_CYCLES`/`KEYBOARD_SHOW_WAIT_MS`/ /// `KEYBOARD_HIDE_WAIT_MS`. const KEYBOARD_CYCLES: usize = 5; const KEYBOARD_WAIT_MS: u64 = 1_000; /// How often this file *asks a question of* the running app -- polls for /// a `ctx.update` closure's answer, or for a fling to have settled. /// /// It is not an animation cadence and nothing on screen moves at this /// rate: the frame loop advances animations once per frame at the /// display's own refresh (`UiData::tick_animations`). It used to be both, /// and that is the defect Iris reported on 2026-09-08 -- see /// `wait_for_fling_settle`. const POLL_MS: u64 = 16; /// How much of the screen a *filled* benchmark report may take before it /// scrolls instead of growing -- roughly a third of a phone screen, the /// share the pane used to reserve unconditionally. An empty report takes /// nothing at all; see `new`'s comment at the tree it is used in. const REPORT_MAX_HEIGHT_DP: f32 = 260.0; pub struct BenchClient { ui_state: AndroidUiState, content: WeakWidget, report_display: WeakWidget, /// The top button row, in a `WidgetPtr` slot rather than added /// directly (like `content`) so `on_insets_changed` can swap in a /// version padded for the status bar once insets are known -- RUST.md's /// P0 box, "the status-bar inset is not applied," found the row sitting /// directly under it because nothing here read `insets().top` at all. top_bar: WeakWidget, screen: Option, items: Vec, /// The events not yet streamed -- consumed by `start_benchmark`'s own /// clone, kept here only as the source a second run would need (the /// button can be pressed more than once; `running` just stops overlap, /// not repeat). stream_tail: Vec, platform: Option>, last_report: Option, running: bool, /// The keyboard phase's own confirmation channel -- updated from /// `on_insets_changed` (the platform's own answer for whether the IME /// is actually visible, per `WindowInsets::ime_bottom`), read from the /// benchmark's spawned task via the shared `Arc>` rather than /// `ctx.update`, since neither side needs the widget tree for this. ime_state: Arc>, /// Edge-triggers the keyboard diagnostics capture below -- set on the /// first `on_insets_changed` where `ime_bottom > 0.0`, cleared on the /// first where it is not, so opening the keyboard fires this once /// rather than on every insets update while it stays open (a rotation /// or a status-bar change with the keyboard already up would otherwise /// re-fire it). keyboard_was_visible: bool, /// The status-bar inset `top_bar` was last padded by -- see /// `on_insets_changed`'s own comment for why this guards the rebuild. last_top_pad: f32, } /// See `BenchClient::ime_state`'s doc. `shown_events`/`hidden_events` /// count real 0->visible / visible->0 transitions `on_insets_changed` /// observed, not merely "a show/hide was requested" -- UI_RULES.md: never /// present an inferred value as a measured one. `run_keyboard_phase` reads /// the counters before and after asking for a toggle and calls it /// confirmed only if the count moved. #[derive(Default)] struct ImeState { visible: bool, shown_events: u32, hidden_events: u32, } impl HasAndroidUiState for BenchClient { fn android_state(&self) -> &AndroidUiState { &self.ui_state } fn android_state_mut(&mut self) -> &mut AndroidUiState { &mut self.ui_state } } fn placeholder(rsc: &mut Rsc, message: &str) -> StrongWidget { wtext(message.to_string()) .color(Color::WHITE) .wrap(true) .pad(16) .add_strong(rsc) .any() } /// `getrusage(RUSAGE_SELF)`'s user+system time, in ms -- `None` only if /// the syscall itself fails, which UI_RULES.md's "never present an /// inferred value as a measured one" says to keep apart from a real (and /// here, impossible) zero. fn process_cpu_ms() -> Option { // SAFETY: `rusage` is a plain-old-data struct `getrusage` fully // initialises on success; on failure it is never read. unsafe { let mut usage: libc::rusage = std::mem::zeroed(); if libc::getrusage(libc::RUSAGE_SELF, &mut usage) != 0 { return None; } let user_ms = usage.ru_utime.tv_sec as u64 * 1000 + usage.ru_utime.tv_usec as u64 / 1000; let sys_ms = usage.ru_stime.tv_sec as u64 * 1000 + usage.ru_stime.tv_usec as u64 / 1000; Some(user_ms + sys_ms) } } /// `VmHWM` from `/proc/self/status` -- the process's peak RSS since it /// started, in kB. Same source `BenchRun.kt`'s `peakRssLine` reads, so the /// two reports' numbers mean the same thing. fn peak_rss_kb() -> Option { std::fs::read_to_string("/proc/self/status") .ok()? .lines() .find_map(|line| line.strip_prefix("VmHWM:")) .and_then(|rest| rest.trim().strip_suffix("kB")) .and_then(|n| n.trim().parse().ok()) } fn battery_line(samples: &[i32]) -> String { if samples.is_empty() { return " battery current: unavailable on this device".to_string(); } let mean = samples.iter().map(|&v| v as i64).sum::() / samples.len() as i64; // `min`/`max` are guarded by the `is_empty` check above, three lines // up -- pairing the `Option` unwraps with the emptiness check right // here (rather than two statements apart, with `mean` in between // reading the same slice) is what keeps a future reorder from // separating the guard from what it protects (review, 2026-09-06 // finding 7). let (Some(min), Some(max)) = (samples.iter().min(), samples.iter().max()) else { unreachable!("samples is non-empty, checked above"); }; format!( " battery current: mean {mean}\u{b5}A over {} samples (min {min}, max {max})", samples.len() ) } impl AndroidAppState for BenchClient { fn new(mut ui_state: AndroidUiState, rsc: &mut AndroidRsc) -> Self { let content = WidgetPtr::new().add(rsc); let loading = placeholder(rsc, "Loading fixture..."); content(rsc).set(loading); let report_display = wtext("") .editable(EditMode::MultiLine) .text_align(Align::LEFT) .wrap(true) .size(14) .color(Color::WHITE) .attr::(()) .label("Benchmark report") .add(rsc); let top_bar = WidgetPtr::new().add(rsc); let controls = bench_controls(rsc, 0.0); top_bar(rsc).set(controls); // The report pane is sized to whatever report it is holding, not // to a share of the window: `rest(1)` here reserved a third of // the screen for an *empty* `TextEdit` at every launch, which is // what Iris's 2026-09-06 11:39 phone report described as "the app // does not start with keyboard spacing correct" -- the composer // two thirds down with black below it, nothing to do with the IME // inset (measured: `iris insets:` reports bottom=63 ime_bottom=0 // at launch, while the `Message` field's own box sat 789px above // the bottom of a 2282px surface -- exactly this pane's third). // Capped and scrollable so a long report cannot take the screen // back over, the same idiom `composer.rs` uses for the field. // Above the transcript, not below it: the report is what the // header's own "Run benchmark" button produces (UI_RULES.md -- // results appear where the action was started), and a pane under // the composer would eat the navigation-bar clearance // `set_bottom_inset` gives it. let tree = ( top_bar, report_display .pad(dp(8)) .max_height(dp(REPORT_MAX_HEIGHT_DP)), content.height(rest(1)), ) .span(Dir::DOWN) .add_strong(rsc) .any(); ui_state.set_root(tree); // Startup log line (RUST.md's P0 box, "log once at startup ... the // number of font families found, the default family resolved"): // what font discovery actually found on this device, before // anything is drawn. let font = rsc.ui.text.font_diagnostics(); log::info!( "iris fonts: {} families found, default={:?} mono={:?}, resolved regular={:?} \ bold={:?} italic={:?} mono={:?}, icons={:?}", font.families_found, font.default_family, font.default_mono_family, font.regular_resolved, font.bold_resolved, font.italic_resolved, font.mono_resolved, font.icon_family, ); let mut client = Self { ui_state, content, report_display, top_bar, screen: None, items: Vec::new(), stream_tail: Vec::new(), platform: None, last_report: None, running: false, ime_state: Arc::new(Mutex::new(ImeState::default())), keyboard_was_visible: false, last_top_pad: 0.0, }; match crate::ui::fixture::build_screen(rsc) { Ok((opened, tree)) => { client.items = opened.items; client.stream_tail = opened.stream_tail; (client.content)(rsc).set(tree); client.screen = Some(opened.screen); } Err(message) => { client.show_message(rsc, &format!("Couldn't fold the bench fixture: {message}")) } } client } fn platform_ready(&mut self, _rsc: &mut AndroidRsc, vm: JavaVM, view: GlobalRef) { self.platform = Some(Arc::new(PlatformHandle::new(vm, view))); } fn back_pressed(&mut self, _rsc: &mut AndroidRsc, _render: &mut UiRenderState) -> bool { false } /// Pads the top button row by the status-bar inset -- see `top_bar`'s /// field comment. Rebuilds the row rather than mutating a stored /// `Padding` in place, since nothing here holds a handle to one -- /// but **only when `insets.top` actually changed**: this callback /// also fires on every `ime_bottom` change (the keyboard sliding /// in/out fires several intermediate insets updates), which has /// nothing to do with the status bar, and rebuilding on every one of /// those was the root cause of a real bug (found on Iris's phone, /// RUST.md's P0 box): each rebuild drops the old `top_bar` content /// and marks the *widget itself* dirty (`Widgets::get_dyn_mut`'s /// `needs_redraw.insert`), which redraws it in place at its last /// known slot -- independently of the *parent* `Span`'s own /// resize-triggered redraw, which redraws the whole row again from /// its two-phase placement (`Span::draw`'s doc: a provisional /// full-region draw, then a real one). A `.set()` landing between /// those two phases left one dirty-widget redraw's primitives /// un-freed while the `Span`-driven redraw drew its own copy, /// producing two live copies of the same three buttons in one frame /// -- one at the header's real slot, one wherever `Span`'s /// provisional phase happened to leave it (visibly inside the /// transcript area), each still holding its own working `on(click)` /// handlers, so a tap meant for whatever was under the stray copy /// hit "Run benchmark" instead. Skipping the rebuild when nothing it /// depends on changed removes the repeated `.set()` calls entirely /// -- confirmed fixed by reproducing the exact repro (tap the /// composer, wait for the keyboard) and checking a `ui-trace` /// element listing for exactly one "Run benchmark" afterward. /// /// Also two things downstream of the same `ime_bottom` transition: /// **the keyboard phase's own confirmation signal** (`ime_state`'s /// doc -- the platform's own answer for whether the IME actually /// opened or closed, rather than assumed from having called /// `show_ime`/`hide_ime`), and **the trigger for the keyboard /// diagnostics capture** (RUST.md's P0 box): the IME resizing the /// surface is exactly the case a previous commit found wiped text, /// and Iris needs a way to get a report off the phone even if that /// (or some other keyboard-triggered regression) is still happening /// on the build she is holding -- `capture_keyboard_diagnostics` /// below fires ~500ms after the keyboard becomes visible, once per /// keyboard opening, and shows its report in a plain overlay view /// that draws independently of whatever iris itself is doing. fn on_insets_changed( &mut self, rsc: &mut AndroidRsc, insets: iris::android::WindowInsets, ) { if insets.top != self.last_top_pad { self.last_top_pad = insets.top; let controls = bench_controls(rsc, insets.top); (self.top_bar)(rsc).set(controls); } // The composer bar sits directly on whichever of the IME or the // navigation bar is currently the bottom of usable space -- see // `crate::ui::composer::Composer::set_bottom_inset`'s doc. // `ime_bottom` already exceeds the plain nav-bar inset whenever the // keyboard covers it, so the larger of the two is always the right // answer without needing to know which is currently showing. if let Some(screen) = &self.screen { screen .composer .set_bottom_inset(rsc, insets.bottom.max(insets.ime_bottom)); } // The platform's own answer, not `ime_bottom > 0.0` -- see // `iris::android::WindowInsets::ime_bottom`. The height is still // climbing while the keyboard slides in, so a frame or two of a // real opening reads as "closed" when the boolean is inferred from // it, and `shown_events`/`hidden_events` below count transitions. let ime_visible = insets.ime_visible; let mut ime = self.ime_state.lock().unwrap(); if ime_visible && !ime.visible { ime.shown_events += 1; } if !ime_visible && ime.visible { ime.hidden_events += 1; } ime.visible = ime_visible; drop(ime); if ime_visible && !self.keyboard_was_visible { self.keyboard_was_visible = true; let redraw = rsc.tasks.redraw_handle(); rsc.spawn_task(async move |mut ctx| { tokio::time::sleep(Duration::from_millis(KEYBOARD_DIAGNOSTICS_DELAY_MS)).await; ctx.update(|state: &mut BenchClient, rsc| { state.capture_keyboard_diagnostics(rsc); }); redraw.request_redraw(); }); } else if !ime_visible { self.keyboard_was_visible = false; } } } /// How long to wait after the keyboard becomes visible before capturing /// diagnostics -- long enough that the resize, the reported wipe (if it is /// still happening) and a couple of frames have all had time to land, per /// AGENTS.md's "so that operations that finish in milliseconds have states /// on the way that nothing can observe" reasoning applied the other way: /// this wants to observe the state *after* the transition settles, not /// mid-flight. const KEYBOARD_DIAGNOSTICS_DELAY_MS: u64 = 500; type Rsc = AndroidRsc; /// What a report says about the `iris::input`/`iris::frame` trace, from /// the flag read at the start of what is being reported and again at the /// end. /// /// Three answers rather than two. Those lines are default-off and the /// switch that turns them on is on screen while a benchmark runs, so /// "somebody moved it half way through" is a state that actually happens /// -- and reported as either "on" or "off" it is a confident sentence /// about a log that only covers part of the run. The "on" wording also /// says what it costs, because a traced run fills the ring in seconds and /// a reader looking at a log with nothing else in it should know why. fn trace_line(at_start: bool, at_end: bool) -> String { match (at_start, at_end) { (true, true) => "input/frame trace: on (iris::input and iris::frame lines are in \ the app log, and a traced run fills the ring in seconds)" .to_string(), (false, false) => "input/frame trace: off".to_string(), _ => "input/frame trace: switched during this run, so those lines cover only part \ of it" .to_string(), } } /// The header row's own backdrop -- see `bench_controls`'s doc comment on /// why it needs one at all. A dark neutral rather than pure black /// (`android::render::CLEAR_COLOR`) so the row reads as a distinct panel /// instead of a hole in the background the buttons happen to float in. const HEADER_SURFACE: UiColor = UiColor::new(28, 28, 34, 255); /// `top_pad` is the status-bar inset in physical pixels (0.0 until /// `on_insets_changed` has run once) -- folded in here, rather than /// exposing the unadded builder for a caller to `.pad()` itself, because /// naming that builder's type at each call site is more machinery than a /// top-of-screen padding number is worth. /// /// **Backed by an opaque rect the full size of the row, not just the three /// buttons.** Iris's phone report (docs/RUST.md's P0 box, screenshots on /// build a9232ac): "the header buttons have nothing behind them and /// overlap the transcript text" -- before this, only each button's own /// `rect(...)` painted anything, so the gaps between and around them (and /// the status-bar strip above them) showed whatever was one layer back /// (`CLEAR_COLOR`, black), and the row's true height was three /// physical-pixel-sized (`abs`, not `dp`) button boxes rather than the /// density-correct size the transcript below was already using post-P0 -- /// exactly what reads as "overlap" once the two disagree. Fixed two ways /// together: a `HEADER_SURFACE` rect stacked behind the whole row (this /// function), and every size below moved from a bare number (physical /// pixels) to `dp(...)` (IRIS_TODO.md's density-independent length unit), /// so the row's reserved height in the outer `Span::DOWN` /// (`AndroidAppState::new`) matches what is actually painted. /// The size every label in the header row is drawn at. /// /// One constant for all four rather than a number per button, because the /// whole row has to be sized together. Adding the trace switch made four /// controls too wide for one row at the size three had used (18), and an /// earlier pass shrank this constant to 13 to make them fit -- exactly /// what UI_RULES forbids ("never shrink text to make it fit": a label a /// different size from its neighbours elsewhere in the app for a reason /// the reader cannot see). The fix is [`bench_controls`]'s two rows /// instead, which leaves room to put this back. Whoever adds a fifth /// control reconsiders the row split, not this number. const HEADER_TEXT: f32 = 18.0; /// The height of one row of header controls, in dp. `bench_controls` now /// stacks two of these, so this is the one number to change if a control's /// own padding ever changes instead of `dp(56)` and `dp(112)` needing to /// be kept in sync by hand. const HEADER_ROW_HEIGHT_DP: f32 = 56.0; fn bench_controls(rsc: &mut Rsc, top_pad: f32) -> StrongWidget { let run_rect = rect(Color::rgb(40, 70, 40)) .on( CursorSense::click(), |ctx: EventIdCtx<'_, Rsc, _, _>, rsc: &mut Rsc| { ctx.state.start_benchmark(rsc); }, ) .label("Run benchmark"); let run = ( run_rect, wtext("Run benchmark") .size(HEADER_TEXT) .text_align(Align::CENTER), ) .stack() .pad(dp(8)) .add(rsc); let copy_rect = rect(Color::rgb(50, 50, 60)) .on( CursorSense::click(), |ctx: EventIdCtx<'_, Rsc, _, _>, rsc: &mut Rsc| { ctx.state.copy_report(rsc); }, ) .label("Copy report"); let copy = ( copy_rect, wtext("Copy report") .size(HEADER_TEXT) .text_align(Align::CENTER), ) .stack() .pad(dp(8)) .add(rsc); let diag_rect = rect(Color::rgb(60, 45, 70)) .on( CursorSense::click(), |ctx: EventIdCtx<'_, Rsc, _, _>, rsc: &mut Rsc| { ctx.state.show_diagnostics(rsc); }, ) .label("Diagnostics"); let diagnostics = ( diag_rect, wtext("Diagnostics") .size(HEADER_TEXT) .text_align(Align::CENTER), ) .stack() .pad(dp(8)) .add(rsc); // A switch rather than a button, so its own appearance says which // state it is in: the two `iris::input`/`iris::frame` targets are // default-off (`iris::diagnostics`'s module doc) because a 120Hz // session fills the 2000-line ring in seconds, so "is it on right // now" is the question somebody has while looking at a log that is // either full of trace or has none. // // The visible text carries the state and the accessibility label does // not, deliberately: the label is also what `run-bench.sh` taps by // name, and a control that renames itself when pressed is one no // script can find twice. let tracing = iris::diagnostics::trace_enabled(); let trace_rect = rect(if tracing { Color::rgb(90, 70, 30) } else { Color::rgb(50, 50, 60) }) .on( CursorSense::click(), |ctx: EventIdCtx<'_, Rsc, _, _>, rsc: &mut Rsc| { ctx.state.toggle_trace(rsc); }, ) .label("Trace input and frames"); let trace = ( trace_rect, wtext(if tracing { "Trace on" } else { "Trace off" }) .size(HEADER_TEXT) .text_align(Align::CENTER), ) .stack() .pad(dp(8)) .add(rsc); // Two rows rather than one: four controls at the restored `HEADER_TEXT` // no longer fit a 1080px-wide row (that was the shrink this replaces -- // see the constant's own doc). Grouped by what they act on: the first // row starts a benchmark and copies its result; the second is the // diagnostics pane and the switch that decides what it will contain // next time. let row1 = (run, copy).span(Dir::RIGHT).add(rsc); let row2 = (diagnostics, trace).span(Dir::RIGHT).add(rsc); let buttons = (row1, row2).span(Dir::DOWN).add(rsc); (rect(HEADER_SURFACE), buttons) .stack() .height(dp(2.0 * HEADER_ROW_HEIGHT_DP)) .pad(Padding::top(top_pad)) .add_strong(rsc) .any() } impl BenchClient { fn show_message(&mut self, rsc: &mut Rsc, message: &str) { let widget = placeholder(rsc, message); (self.content)(rsc).set(widget); self.screen = None; } fn rebuild_transcript(&mut self, rsc: &mut Rsc) { let (screen, tree) = crate::ui::build_tree(rsc, crate::ui::fixture::rows(&self.items)); (self.content)(rsc).set(tree); self.screen = Some(screen); } /// RUST.md's P0 box: "a named `Diagnostics` control ... with 'copy this /// and send it to Iris'." Fills `report_display` (the same TextEdit the /// benchmark report uses) rather than a separate widget, so the /// existing "Copy report" button and clipboard path work on whichever /// text is currently shown -- `last_report` is what `copy_report` reads, /// so it's set here too rather than adding a second copy path. fn show_diagnostics(&mut self, rsc: &mut Rsc) { let report = self.diagnostics_text(rsc); self.report_display.edit(rsc).set(&report); self.last_report = Some(report); } /// Turns the `iris::input`/`iris::frame` trace on or off, redraws the /// switch that says so, and shows the pane that now reports it. /// /// Showing the pane is the point rather than a convenience: this is a /// control whose whole effect is on what a *later* report says, so /// putting the state on screen at the moment of the press is the only /// thing that distinguishes it from a button that did nothing. fn toggle_trace(&mut self, rsc: &mut Rsc) { let on = !iris::diagnostics::trace_enabled(); iris::diagnostics::set_trace(on); log::info!( "iris diagnostics: input/frame trace {}", if on { "on" } else { "off" } ); let controls = bench_controls(rsc, self.last_top_pad); (self.top_bar)(rsc).set(controls); self.show_diagnostics(rsc); } /// The diagnostics report as text, with no side effect on what is on /// screen -- shared by the `Diagnostics` button (which shows it) and /// the keyboard-open capture (which only logs it), so the two can /// never drift into reporting different things. fn diagnostics_text(&self, rsc: &mut Rsc) -> String { let font = rsc.ui.text.font_diagnostics(); let frame_report = match self.android_state().frame_report.report() { Some(stats) => format!("{stats}"), None => "no frames recorded yet".to_string(), }; let renderer = match &self.android_state().renderer { Some(renderer) => renderer.diagnostics_report(&font, &frame_report), None => "iris diagnostics: no renderer yet (no surface)".to_string(), }; // The insets line goes in the pane, not just the log: Iris has no // logcat on her phone, and "the keyboard does not push the // composer up" cannot be told from "the listener never fired" // without it (`AndroidUiState::insets_report`). format!( "{renderer}\n{}\n{}\n{}\n{}", trace_line( iris::diagnostics::trace_enabled(), iris::diagnostics::trace_enabled() ), self.android_state().insets_report(), // Which server this build talks to, and what to do when the // answer is "none" -- the bench itself opens a checked-in // fixture and needs no server, so this pane is the only place // an enrolment can be seen to have taken. crate::android::enrollment::status_line(), crate::android::app_log::diagnostics_line() ) } /// The keyboard's own diagnostics capture -- see `on_insets_changed`'s /// doc comment. **Logged only.** It used to also copy the report to /// the clipboard unprompted and put it in the shell's overlay view, /// from when the keyboard-inset callback was not firing at all and a /// report could not be got off the phone any other way. Both are gone /// as of 2026-09-06: the callback fires reliably now (edge-to-edge, /// `MainActivity.java`), and the overlay covered the whole screen on /// *every* keyboard open with its own Copy/Close buttons underneath /// the keyboard, so it could not be dismissed -- an interruption for /// something nobody asked for, over an app you are trying to type /// into (UI_RULES.md). The named `Diagnostics` button still shows the /// same text on demand, and `iris surface:`/`iris insets:` (view.rs) /// carry the lifecycle a `logcat` pull actually needs. fn capture_keyboard_diagnostics(&mut self, rsc: &mut Rsc) { let report = self.diagnostics_text(rsc); log::info!("iris keyboard diagnostics:\n{report}"); } /// Always copies something, and never depends on `Diagnostics` or /// `Run benchmark` having been pressed first (docs/IRIS_TODO.md, /// 2026-09-07 night: "the copy report button seemed impossible to hit /// until I hit the diagnostics one" -- it was silently declining /// instead of reporting where it had failed, the UI_RULES failure "a /// failure is reported where it happened"). With no benchmark run yet, /// it copies the diagnostics pane's own text instead, with a first /// line saying so -- `diagnostics_text` needs no prior button press /// either, so this is never actually empty-handed. /// The report carries **no copy of the app log** (removed 2026-09-08, /// Iris: "please remove the app log from the diagnostics. Those can be /// obtained through dev updater now"). Dev Updater's Runtime tab reads /// the same ring through `devlog`'s provider, and the diagnostics /// pane's own `devlog provider:` line names the authority to read it /// from -- so what is left here is the measurement, not a second copy /// of something already reachable. fn copy_report(&mut self, rsc: &mut Rsc) { let Some(platform) = &self.platform else { log::info!("iris bench report: no platform handle, can't reach the clipboard"); return; }; let report = match self.last_report.clone() { Some(report) => report, None => format!( "no benchmark has run yet -- these are the diagnostics instead:\n\n{}", self.diagnostics_text(rsc) ), }; if platform.copy_to_clipboard("iris bench report", &report) { log::info!("iris bench report: copied to clipboard"); } else { log::info!("iris bench report: clipboard copy failed"); } } /// RUST.md's "Benchmark v2": fling, then stream (unchanged from v1), /// then type, then keyboard, then the report -- run in-process for the /// same reason `BenchRun.kt`'s own doc gives (no usable system tracing /// on a real phone, no agent that can drive one). fn start_benchmark(&mut self, rsc: &mut Rsc) { if self.running { log::info!("iris bench report: already running"); return; } self.running = true; self.android_state_mut().frame_report.reset(); self.report_display.edit(rsc).set("Running benchmark..."); let redraw = rsc.tasks.redraw_handle(); let platform = self.platform.clone(); let stream_tail = self.stream_tail.clone(); let ime_state = self.ime_state.clone(); let refresh_hz = platform .as_ref() .and_then(|p| p.refresh_rate_hz()) .unwrap_or(60.0); let cpu_start = process_cpu_ms(); // Read at the start as well as the end, because the switch is on // screen while a run is going: a report that only asked afterwards // would say "on" about a run whose first half has no trace in it // -- the inferred answer presented as the measured one. let trace_at_start = iris::diagnostics::trace_enabled(); let run_started_at = Instant::now(); rsc.spawn_task(async move |mut ctx| { // The battery sampler runs for the whole run, once a second, // the same cadence `BatterySampler` uses on the Compose side // -- via its own JNI-attached thread, not `ctx.update`, since // a sample needs no widget-tree access. let sampler_done = Arc::new(AtomicBool::new(false)); let samples = Arc::new(Mutex::new(Vec::::new())); let sampler = platform.clone().map(|platform| { let done = sampler_done.clone(); let samples = samples.clone(); tokio::spawn(async move { while !done.load(Ordering::Relaxed) { if let Some(value) = platform.battery_current_ua() { samples.lock().unwrap().push(value); } tokio::time::sleep(Duration::from_secs(1)).await; } }) }); let travel = run_fling_phase(&mut ctx, &redraw).await; let (sent, total) = run_stream_phase(&mut ctx, &redraw, stream_tail).await; run_type_phase(&mut ctx, &redraw, &platform).await; let keyboard = run_keyboard_phase(&mut ctx, &platform, &ime_state).await; sampler_done.store(true, Ordering::Relaxed); if let Some(sampler) = sampler { let _ = sampler.await; } let battery = battery_line(&samples.lock().unwrap()); let cpu_line = match (cpu_start, process_cpu_ms()) { (Some(start), Some(end)) => { format!( " process CPU time over this run: {}ms", end.saturating_sub(start) ) } _ => " process CPU time over this run: unavailable".to_string(), }; let rss_line = match peak_rss_kb() { Some(kb) => format!(" peak RSS: {kb}kB"), None => " peak RSS: unavailable (/proc/self/status unreadable)".to_string(), }; let total_seconds = run_started_at.elapsed().as_secs_f64(); ctx.update(move |state: &mut BenchClient, rsc| { state.running = false; let now = Instant::now(); let phase_lines: String = state .android_state() .frame_report .phase_stats(now, refresh_hz) .iter() .map(|p| format!("{p}\n")) .collect(); let per_phase = if phase_lines.is_empty() { String::new() } else { format!("per phase:\n{phase_lines}\n") }; let frames_block = match state.android_state().frame_report.report() { Some(stats) => { let (late, late_pct) = state.android_state().frame_report.late_at_hz(refresh_hz); format!( "frames:\n {} frames over {:.1}s at {:.0}Hz ({:.1}ms budget)\n \ late: {late} ({late_pct:.1}%)\n total p50 {:.1}ms p90 {:.1}ms \ p99 {:.1}ms\n worst {:.1}ms\n cpu_p50 {:.1}ms gpu_wait_p50 {:.1}ms", stats.total_frames, total_seconds, refresh_hz, 1000.0 / refresh_hz as f64, stats.p50.as_secs_f64() * 1000.0, stats.p90.as_secs_f64() * 1000.0, stats.p99.as_secs_f64() * 1000.0, stats.worst.as_secs_f64() * 1000.0, stats.cpu_p50.as_secs_f64() * 1000.0, stats.gpu_wait_p50.as_secs_f64() * 1000.0, ) } None => "frames:\n no frames recorded".to_string(), }; let scroll_line = format!( " scroll: {LEGACY_CYCLES} cycles ({} swipes, legacy tween), streamed \ {sent}/{total} fixture events", LEGACY_CYCLES * 4 ); let fling_line = format!( " fling: {FLING_COUNT} flings out + {FLING_COUNT} back at \ {FLING_VELOCITY_PX_S}px/s, travel {travel}" ); let type_line = format!( " type: {} characters inserted then deleted, one per {TYPE_CHAR_MS}ms", TYPE_TEXT.chars().count() ); let traced = trace_line(trace_at_start, iris::diagnostics::trace_enabled()); let report = format!( "iris bench report\n{traced}\n{per_phase}{frames_block}\n\nbench:\n\ {fling_line}\n{scroll_line}\n{type_line}\n{keyboard}\n{cpu_line}\n\ {rss_line}\n{battery}" ); log::info!("iris bench report: {report}"); state.report_display.edit(rsc).set(&report); state.last_report = Some(report); }); redraw.request_redraw(); }); } } /// Runs `f` against the real `BenchClient`/`Rsc` on the main thread (the /// same `ctx.update` every other mutation here goes through) and returns /// its result to the caller's async task -- `ctx.update` alone has no way /// to hand a value back, since the closure only actually runs once the /// next frame callback drains `IrisViewPeer`'s task channel /// (`drain_tasks`). **Must call `redraw.request_redraw()` itself, right /// after enqueueing** -- `ctx.update` only ever pushes onto a channel; /// nothing drains it until something schedules the frame callback that /// calls `drain_tasks`, and a caller relying on some *earlier*, /// already-in-flight `request_redraw()` to cover a *later* `ctx.update` /// deadlocks the moment that earlier callback has already fired and /// drained everything queued before this call existed. Cost a real hang /// in this file's first version of the fling phase: every loop iteration /// after the first sat forever with nothing scheduled to drain it. /// Polls rather than assuming one `POLL_MS` sleep is enough, since a /// slow device's frame callback can lag further than that. async fn read_from_state( ctx: &mut iris::task::TaskCtx, redraw: &Arc, f: F, ) -> T where T: Send + 'static, F: FnOnce(&mut BenchClient, &mut Rsc) -> T + Send + 'static, { let (tx, rx) = std::sync::mpsc::channel(); ctx.update(move |state: &mut BenchClient, rsc| { let _ = tx.send(f(state, rsc)); }); redraw.request_redraw(); loop { if let Ok(value) = rx.try_recv() { return value; } tokio::time::sleep(Duration::from_millis(POLL_MS)).await; } } /// Phase 1: starting pinned at the newest end, `FLING_COUNT` flings away /// from it (toward older messages) through `Scroll::fling`, then /// `FLING_COUNT` back. Outward is *positive* in `Scroll::scroll`'s /// convention, which is the finger's: a finger dragged down the screen /// brings earlier content into view. It was negative here until /// 2026-09-08, when the transcript's scroll position moved out of the /// `LazySpan` -- whose anchor offset ran the other way -- and into the /// `ScrollArea` around it. The two apps' *travel* is directly comparable /// whichever way the signs run, because both report it as a row index plus /// a pixel offset rather than a signed distance. async fn run_fling_phase( ctx: &mut iris::task::TaskCtx, redraw: &Arc, ) -> String { ctx.update(|state: &mut BenchClient, _rsc| { state.android_state_mut().frame_report.mark_phase("fling"); }); ctx.update(|state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { (screen.list)(rsc).jump_to_end(); } }); redraw.request_redraw(); // Lets the next frame's `repair_anchor` resolve `jump_to_end`'s // `anchor = None` into a real slot before `start` is read. tokio::time::sleep(Duration::from_millis(POLL_MS * 2)).await; let start = read_anchor_position(ctx, redraw).await; for _ in 0..FLING_COUNT { ctx.update(|state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { (screen.list)(rsc).fling(FLING_VELOCITY_PX_S); animate_scroll(screen.list, rsc); } }); redraw.request_redraw(); wait_for_fling_settle(ctx, redraw).await; tokio::time::sleep(Duration::from_millis(FLING_PAUSE_MS)).await; } let outward = read_anchor_position(ctx, redraw).await; for _ in 0..FLING_COUNT { ctx.update(|state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { (screen.list)(rsc).fling(-FLING_VELOCITY_PX_S); animate_scroll(screen.list, rsc); } }); redraw.request_redraw(); wait_for_fling_settle(ctx, redraw).await; tokio::time::sleep(Duration::from_millis(FLING_PAUSE_MS)).await; } let end = read_anchor_position(ctx, redraw).await; // Says how the fling was advanced, because that is what changed on // 2026-09-08 and a report from before then is not comparable: the // phase used to tick the fling itself at ~60Hz. format!("start={start} outward={outward} end={end} ticked=frame-loop") } async fn read_anchor_position( ctx: &mut iris::task::TaskCtx, redraw: &Arc, ) -> String { read_from_state(ctx, redraw, |state, rsc| match &state.screen { Some(screen) => (screen.list)(rsc).anchor_position_display(), None => "idx=none".to_string(), }) .await } /// Register the scrolling widget with the frame loop, exactly as a /// finger's own release does (`crate::ui::Selection::drag`'s /// `Released` arm) -- `Scrollable::fling` sets a velocity and drives /// nothing by itself. fn animate_scroll(scroll: iris::prelude::WeakWidget, rsc: &mut Rsc) { let id = scroll.id(); rsc.ui_mut().animate(id); } /// Waits for the fling started above to settle, or for /// `FLING_SETTLE_CAP_MS` -- belt-and-suspenders the same way /// `BenchRun.kt`'s own `waitForSettle` is, since a fling's own /// spline-decided `duration()` already caps how long it can run. /// /// **It observes; it does not drive.** Until 2026-09-08 this loop called /// `Scrollable::tick_fling` itself every `POLL_MS`, which advanced the /// fling in 16ms steps -- so on Iris's 120Hz phone every second frame /// redrew the list at a position it had already drawn, and the benchmark /// looked distinctly less smooth than the same list under her finger. /// That is what she reported that day, and it was the rig rather than the /// renderer: a real fling is ticked once per frame by /// `UiData::tick_animations`, from the frame callback. So the bench now /// starts the fling the way a gesture does (`fling` + `UiData::animate`) /// and polls `is_scrolling` to know when it is over, which makes the /// phase measure the same path a finger takes. The poll interval is only /// how often the *question* is asked and has no bearing on the animation. async fn wait_for_fling_settle( ctx: &mut iris::task::TaskCtx, redraw: &Arc, ) { let cap = Duration::from_millis(FLING_SETTLE_CAP_MS); let started = Instant::now(); while started.elapsed() < cap { let still_scrolling = read_from_state(ctx, redraw, |state, rsc| match &state.screen { Some(screen) => (screen.list)(rsc).is_scrolling(), None => false, }) .await; if !still_scrolling { return; } tokio::time::sleep(Duration::from_millis(POLL_MS)).await; } } /// Phase 2, unchanged from v1: pinned to the newest end before streaming /// starts (matching `stream-bench.sh`'s "Jump to latest" tap), then /// `STREAM_EVENTS_PER_SEC * STREAM_SECONDS` fixture events replayed /// through the real `fold_event`/`TranscriptScreen::apply` path. Returns /// `(sent, total)`. async fn run_stream_phase( ctx: &mut iris::task::TaskCtx, redraw: &Arc, stream_tail: Vec, ) -> (usize, usize) { ctx.update(|state: &mut BenchClient, _rsc| { state.android_state_mut().frame_report.mark_phase("stream"); }); ctx.update(|state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { (screen.list)(rsc).jump_to_end(); } }); redraw.request_redraw(); let total = (STREAM_EVENTS_PER_SEC * STREAM_SECONDS) as usize; let mut sent = 0usize; for event in stream_tail.into_iter().take(total) { ctx.update(move |state: &mut BenchClient, rsc| { let old_items = state.items.clone(); state.items = fold_event(&state.items, &event); match &state.screen { Some(screen) => screen.apply(rsc, &old_items, &state.items), None => state.rebuild_transcript(rsc), } }); redraw.request_redraw(); sent += 1; tokio::time::sleep(Duration::from_millis(1000 / STREAM_EVENTS_PER_SEC)).await; } // Lets the last few deltas land and draw before the next phase starts // -- `BenchRun.kt`'s own closing delay. tokio::time::sleep(Duration::from_millis(300)).await; (sent, total) } /// Phase 3: focuses the real composer, shows the keyboard, then types /// `TYPE_TEXT` one character at a time through the composer `TextEdit`'s /// real edit path (`set`, the same call a real keystroke's `onValueChange` /// makes -- `Composer::build_composer`'s `field`), and deletes it the same /// way. async fn run_type_phase( ctx: &mut iris::task::TaskCtx, redraw: &Arc, platform: &Option>, ) { ctx.update(|state: &mut BenchClient, _rsc| { state.android_state_mut().frame_report.mark_phase("type"); }); ctx.update(|state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { (screen.list)(rsc).jump_to_end(); state.set_focus(Some(screen.composer.field)); } }); redraw.request_redraw(); if let Some(p) = platform { p.show_ime(); } // Lets focus and the keyboard's opening animation land before typing // starts, so the frames this phase records are the wrap/reflow it is // measuring, not the keyboard opening -- `BenchRun.kt`'s own delay. tokio::time::sleep(Duration::from_millis(300)).await; let mut typed = String::new(); for ch in TYPE_TEXT.chars() { typed.push(ch); let text = typed.clone(); ctx.update(move |state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { screen.composer.field.edit(rsc).set(&text); } }); redraw.request_redraw(); tokio::time::sleep(Duration::from_millis(TYPE_CHAR_MS)).await; } tokio::time::sleep(Duration::from_millis(200)).await; while !typed.is_empty() { typed.pop(); let text = typed.clone(); ctx.update(move |state: &mut BenchClient, rsc| { if let Some(screen) = &state.screen { screen.composer.field.edit(rsc).set(&text); } }); redraw.request_redraw(); tokio::time::sleep(Duration::from_millis(TYPE_CHAR_MS)).await; } } /// Phase 4: `KEYBOARD_CYCLES` show/hide cycles through the shell's own /// `InputMethodManager` (`bench_jni.rs`'s `show_ime`/`hide_ime`), each /// confirmed by `on_insets_changed`'s real `ime_bottom` transition rather /// than assumed from the JNI call having returned -- `ImeState`'s doc. /// "keyboard: could not be shown" if the platform never confirms it even /// once, per UI_RULES.md ("design the unknown/failed state before the /// answer's"). async fn run_keyboard_phase( ctx: &mut iris::task::TaskCtx, platform: &Option>, ime_state: &Arc>, ) -> String { ctx.update(|state: &mut BenchClient, _rsc| { state .android_state_mut() .frame_report .mark_phase("keyboard"); }); let mut shown = 0; let mut hidden = 0; for _ in 0..KEYBOARD_CYCLES { let before_shown = ime_state.lock().unwrap().shown_events; if let Some(p) = platform { p.show_ime(); } tokio::time::sleep(Duration::from_millis(KEYBOARD_WAIT_MS)).await; if ime_state.lock().unwrap().shown_events > before_shown { shown += 1; } let before_hidden = ime_state.lock().unwrap().hidden_events; if let Some(p) = platform { p.hide_ime(); } tokio::time::sleep(Duration::from_millis(KEYBOARD_WAIT_MS)).await; if ime_state.lock().unwrap().hidden_events > before_hidden { hidden += 1; } } if shown == 0 { format!(" keyboard: could not be shown ({KEYBOARD_CYCLES} attempts, 0 confirmed visible)") } else { format!( " keyboard: shown {shown}/{KEYBOARD_CYCLES}, hidden {hidden}/{KEYBOARD_CYCLES} \ (confirmed via on_insets_changed)" ) } } #[cfg(test)] mod tests { use super::TYPE_TEXT; /// `BenchRun.kt`'s own `TYPE_TEXT` is verified `.length == 600`; this /// is the same string, so it has to match exactly or the two apps' /// type phases stop typing the same content -- RUST.md's "Benchmark /// v2" spec is one shared string for both. #[test] fn type_text_is_exactly_600_characters() { assert_eq!(TYPE_TEXT.chars().count(), 600); } }