iris android-app: Benchmark v2 -- fling, type and keyboard phases
Implements RUST.md's "Benchmark v2" spec in bench_client.rs: fling (8 out + 8 back at 12,000px/s through List::fling, waits for !is_scrolling() capped 3s, reports travel as row index + offset via List's new anchor_position_display), stream (unchanged), type (the 600-char P0 constant, one char per 50ms into the composer's real TextEdit via .set(), then deleted), and keyboard (5 show/hide cycles via bench_jni.rs's new InputMethodManager calls, confirmed from on_insets_changed's real ime_bottom transitions rather than assumed from the JNI call returning). FrameReport gained mark_phase/phase_stats/late_at_hz (iris/core) so the report can show a per-phase block (frames, late%, p50/p90/p99, worst) against the display's real refresh rate (bench_jni's new refresh_rate_hz), matching the shape docs/bench/compose-phone-v2 uses. RING_CAPACITY bumped 4096->16384 since a full v2 run is ~3,000+ frames. Found and fixed a real deadlock while wiring this up: read_from_state (a new helper that gets a value back out of a spawned task's ctx.update, which has no return channel of its own) only worked for its first call in a chain, because nothing called redraw.request_redraw() after enqueueing later ones -- nothing then drains the task channel to run them. Every call now triggers its own redraw. Verified end to end on this checkout's x86_64 emulator (force-gles, cold boot): fling/stream/type all report populated phase blocks; keyboard's show never got a real on_insets_changed confirmation this run (see follow-up work). Full report and travel numbers go in RUST.md's P0 box next. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
This commit is contained in:
irisandClaude Fable 5.1 committed
1 parent
2d3695a1d3
commit
1aab61bf26
5 files changed
+836
-102
No files matched your search
@@ -46,10 +46,13 @@ adb -s "$SERIAL" shell am start -n "$PKG/dev.iris.android.demo.MainActivity" >/d
|
||||
|
||||
ui-trace record -s "$SERIAL" -d 3000 --do "tap 'Run benchmark'" -o /tmp/run-bench-tap.txt >/dev/null
|
||||
|
||||
# Poll for the report line rather than a fixed sleep -- the run itself is a
|
||||
# fixed script (24 swipes + a 20s streaming phase) but device speed varies.
|
||||
# Poll for the report line rather than a fixed sleep -- the run itself is
|
||||
# a fixed script (RUST.md's "Benchmark v2": 16 flings, a 20s streaming
|
||||
# phase, ~61s of typing, 10s of keyboard toggles, roughly 2.5 minutes end
|
||||
# to end) but device speed varies. 260s cap rather than v1's 90s -- v2 is
|
||||
# a longer script than v1's swipe-loop-only run.
|
||||
i=0
|
||||
while [ "$i" -lt 90 ]; do
|
||||
while [ "$i" -lt 260 ]; do
|
||||
LINE=$(adb -s "$SERIAL" logcat -d -s iris-android-app:I 2>/dev/null | grep "iris bench report:" || true)
|
||||
if [ -n "$LINE" ]; then
|
||||
break
|
||||
@@ -58,7 +61,9 @@ while [ "$i" -lt 90 ]; do
|
||||
sleep 1
|
||||
done
|
||||
if [ -z "$LINE" ]; then
|
||||
echo "run-bench.sh: no report after 90s -- check logcat by hand" >&2
|
||||
echo "run-bench.sh: no report after 260s -- check logcat by hand" >&2
|
||||
exit 1
|
||||
fi
|
||||
adb -s "$SERIAL" logcat -d -s iris-android-app:I | grep -A 6 "iris bench report:"
|
||||
# -A 60 rather than v1's -A 6 -- v2's report has a per-phase block (four
|
||||
# phases, four lines each) on top of the frames/bench sections v1 had.
|
||||
adb -s "$SERIAL" logcat -d -s iris-android-app:I | grep -A 60 "iris bench report:"
|
||||
@@ -26,9 +26,9 @@ use client_core::transcript_fold::{TranscriptItem, fold_event, fold_page, group_
|
||||
use event_model::SeqEvent;
|
||||
use iris::android::{AndroidAppState, AndroidRsc, AndroidUiState, HasAndroidUiState};
|
||||
use iris::prelude::*;
|
||||
use std::sync::Arc;
|
||||
use std::sync::atomic::{AtomicBool, Ordering};
|
||||
use std::time::Duration;
|
||||
use std::sync::{Arc, Mutex};
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
/// bench-fixture/README.md: the first `BACKLOG_COUNT` non-blank lines are
|
||||
/// the opening window; the rest are the streaming tail. Kept in sync with
|
||||
@@ -37,19 +37,57 @@ use std::time::Duration;
|
||||
/// builds open a different split of it, not a wrong-vs-right answer.
|
||||
const BACKLOG_COUNT: usize = 3200;
|
||||
|
||||
/// `BenchRun.kt`'s own constants -- kept identical so the two apps' bench
|
||||
/// runs are the same gesture and the same load, which is the entire point
|
||||
/// of a shared fixture and a shared scripted loop (P0's pass condition).
|
||||
const CYCLES: usize = 6;
|
||||
const SWIPE_PX: f32 = 900.0;
|
||||
const SWIPE_MS: u64 = 200;
|
||||
const SWIPE_PAUSE_MS: u64 = 500;
|
||||
/// 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 `List::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;
|
||||
|
||||
/// One animation step's target cadence -- close enough to 60Hz that a
|
||||
/// `List::scroll` swipe is many small moves rather than one jump, so
|
||||
/// frames are actually rendered along the way (the point of animating it
|
||||
/// at all rather than calling `scroll` once per swipe).
|
||||
/// fling/scroll is many small moves rather than one jump, so frames are
|
||||
/// actually rendered along the way, and close enough that a `ctx.update`
|
||||
/// closure's effect (only applied once the next frame callback drains the
|
||||
/// task channel -- `IrisViewPeer::drain_tasks`) is visible again quickly
|
||||
/// when a later step in the same phase needs to read state back.
|
||||
const ANIM_STEP_MS: u64 = 16;
|
||||
|
||||
const FIXTURE_JSONL: &str = include_str!("../../../app/bench-fixture/assets/transcript.jsonl");
|
||||
@@ -74,6 +112,25 @@ pub struct BenchClient {
|
||||
platform: Option<Arc<PlatformHandle>>,
|
||||
last_report: Option<String>,
|
||||
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 `LogicalInsets::ime_bottom`), read from the
|
||||
/// benchmark's spawned task via the shared `Arc<Mutex<_>>` rather than
|
||||
/// `ctx.update`, since neither side needs the widget tree for this.
|
||||
ime_state: Arc<Mutex<ImeState>>,
|
||||
}
|
||||
|
||||
/// 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 {
|
||||
@@ -219,6 +276,7 @@ impl AndroidAppState for BenchClient {
|
||||
platform: None,
|
||||
last_report: None,
|
||||
running: false,
|
||||
ime_state: Arc::new(Mutex::new(ImeState::default())),
|
||||
};
|
||||
|
||||
let (backlog, stream_tail) = parse_fixture();
|
||||
@@ -246,9 +304,29 @@ impl AndroidAppState for BenchClient {
|
||||
/// 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.
|
||||
fn on_insets_changed(&mut self, rsc: &mut AndroidRsc<Self>, insets: iris::android::LogicalInsets) {
|
||||
///
|
||||
/// Also the keyboard phase's own confirmation signal: `ime_bottom`
|
||||
/// crossing 0<->positive is the platform's own answer for whether the
|
||||
/// IME actually opened or closed, fired from the real insets
|
||||
/// callback rather than assumed from having called `show_ime`/
|
||||
/// `hide_ime` -- see `ime_state`'s doc.
|
||||
fn on_insets_changed(
|
||||
&mut self,
|
||||
rsc: &mut AndroidRsc<Self>,
|
||||
insets: iris::android::LogicalInsets,
|
||||
) {
|
||||
let controls = bench_controls(rsc, insets.top);
|
||||
(self.top_bar)(rsc).set(controls);
|
||||
|
||||
let mut ime = self.ime_state.lock().unwrap();
|
||||
let now_visible = insets.ime_bottom > 0.0;
|
||||
if now_visible && !ime.visible {
|
||||
ime.shown_events += 1;
|
||||
}
|
||||
if !now_visible && ime.visible {
|
||||
ime.hidden_events += 1;
|
||||
}
|
||||
ime.visible = now_visible;
|
||||
}
|
||||
}
|
||||
|
||||
@@ -366,10 +444,10 @@ impl BenchClient {
|
||||
}
|
||||
}
|
||||
|
||||
/// P0's scripted run: `BenchRun.kt`'s scroll loop, then its streaming
|
||||
/// phase, then the report -- run in-process for the same reason that
|
||||
/// file's own doc gives (no usable system tracing on a real phone, no
|
||||
/// agent that can drive one).
|
||||
/// 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");
|
||||
@@ -382,35 +460,21 @@ impl BenchClient {
|
||||
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();
|
||||
let run_started_at = Instant::now();
|
||||
|
||||
rsc.spawn_task(async move |mut ctx| {
|
||||
// The swipe loop: two drags toward newer content, two back --
|
||||
// a cycle returns to where it started, so the whole loop
|
||||
// measures steady-state scrolling. `BenchRun.kt`'s own
|
||||
// comment on this shape.
|
||||
for _ in 0..CYCLES {
|
||||
for delta in [SWIPE_PX, SWIPE_PX, -SWIPE_PX, -SWIPE_PX] {
|
||||
animate_scroll(&mut ctx, &redraw, delta, SWIPE_MS).await;
|
||||
tokio::time::sleep(Duration::from_millis(SWIPE_PAUSE_MS)).await;
|
||||
}
|
||||
}
|
||||
|
||||
// Pinned to the newest end before streaming starts, matching
|
||||
// `stream-bench.sh`'s "Jump to latest" tap.
|
||||
ctx.update(|state: &mut BenchClient, rsc| {
|
||||
if let Some(screen) = &state.screen {
|
||||
(screen.list)(rsc).jump_to_end();
|
||||
}
|
||||
});
|
||||
redraw.request_redraw();
|
||||
|
||||
// The battery sampler runs concurrently with the streaming
|
||||
// phase, 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.
|
||||
// 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(std::sync::Mutex::new(Vec::<i32>::new()));
|
||||
let samples = Arc::new(Mutex::new(Vec::<i32>::new()));
|
||||
let sampler = platform.clone().map(|platform| {
|
||||
let done = sampler_done.clone();
|
||||
let samples = samples.clone();
|
||||
@@ -424,27 +488,10 @@ impl BenchClient {
|
||||
})
|
||||
});
|
||||
|
||||
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 {
|
||||
// The path P0 asked to measure: update only the
|
||||
// row(s) that changed instead of rebuilding all
|
||||
// ~3,200 of them per event.
|
||||
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 report is
|
||||
// read -- `BenchRun.kt`'s own closing delay.
|
||||
tokio::time::sleep(Duration::from_millis(300)).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 {
|
||||
@@ -453,7 +500,10 @@ impl BenchClient {
|
||||
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))
|
||||
format!(
|
||||
" process CPU time over this run: {}ms",
|
||||
end.saturating_sub(start)
|
||||
)
|
||||
}
|
||||
_ => " process CPU time over this run: unavailable".to_string(),
|
||||
};
|
||||
@@ -461,19 +511,61 @@ impl BenchClient {
|
||||
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 scroll_line = format!(
|
||||
" scroll: {CYCLES} cycles ({} swipes), streamed {sent}/{total} fixture events",
|
||||
CYCLES * 4
|
||||
);
|
||||
let frames_line = match state.android_state().frame_report.report() {
|
||||
Some(stats) => format!("{stats}"),
|
||||
None => "no frames recorded".to_string(),
|
||||
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 report = format!(
|
||||
"iris bench report\n{frames_line}\n{scroll_line}\n{cpu_line}\n{rss_line}\n{battery}"
|
||||
"iris bench report\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);
|
||||
@@ -484,26 +576,287 @@ impl BenchClient {
|
||||
}
|
||||
}
|
||||
|
||||
/// Moves `List::scroll` by `total_px` over `duration_ms`, in ~60Hz steps,
|
||||
/// so the swipe is many rendered frames rather than one jump -- the same
|
||||
/// shape `animateScrollBy(SWIPE_PX, tween(SWIPE_MS))` gives on the Compose
|
||||
/// side, in the one place the two backends have to differ (iris's `List`
|
||||
/// has no built-in tween, so this drives it by hand).
|
||||
async fn animate_scroll(
|
||||
/// 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 `ANIM_STEP_MS` sleep is enough, since a
|
||||
/// slow device's frame callback can lag further than that.
|
||||
async fn read_from_state<T, F>(
|
||||
ctx: &mut iris::task::TaskCtx<Rsc>,
|
||||
redraw: &Arc<dyn iris::task::RequestRedraw>,
|
||||
total_px: f32,
|
||||
duration_ms: u64,
|
||||
) {
|
||||
let steps = (duration_ms / ANIM_STEP_MS).max(1);
|
||||
let step_px = total_px / steps as f32;
|
||||
for _ in 0..steps {
|
||||
redraw: &Arc<dyn RequestRedraw>,
|
||||
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| {
|
||||
if let Some(screen) = &state.screen {
|
||||
(screen.list)(rsc).scroll(step_px);
|
||||
}
|
||||
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(ANIM_STEP_MS)).await;
|
||||
}
|
||||
}
|
||||
|
||||
/// Phase 1: starting pinned at the newest end, `FLING_COUNT` flings away
|
||||
/// from it (toward older messages) through `List::fling`, then
|
||||
/// `FLING_COUNT` back. Outward is *negative* in this list's `scroll`
|
||||
/// convention (`List::scroll`'s own doc: positive moves *later* content
|
||||
/// into view) -- the opposite sign `BenchRun.kt`'s `runFlingPhase` uses,
|
||||
/// since `TranscriptList`'s `LazyColumn` and this list define "positive"
|
||||
/// the other way around; the two apps' *travel* is still directly
|
||||
/// comparable because both report it as a row index + pixel offset, not a
|
||||
/// signed distance.
|
||||
async fn run_fling_phase(
|
||||
ctx: &mut iris::task::TaskCtx<Rsc>,
|
||||
redraw: &Arc<dyn RequestRedraw>,
|
||||
) -> 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(ANIM_STEP_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);
|
||||
}
|
||||
});
|
||||
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);
|
||||
}
|
||||
});
|
||||
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;
|
||||
|
||||
format!("start={start} outward={outward} end={end}")
|
||||
}
|
||||
|
||||
async fn read_anchor_position(
|
||||
ctx: &mut iris::task::TaskCtx<Rsc>,
|
||||
redraw: &Arc<dyn RequestRedraw>,
|
||||
) -> 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
|
||||
}
|
||||
|
||||
/// Ticks the fling forward in ~60Hz steps (the same shape
|
||||
/// `run_stream_phase`'s per-event loop and the old `animate_scroll` used)
|
||||
/// until it settles or `FLING_SETTLE_CAP_MS` passes -- 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.
|
||||
async fn wait_for_fling_settle(
|
||||
ctx: &mut iris::task::TaskCtx<Rsc>,
|
||||
redraw: &Arc<dyn RequestRedraw>,
|
||||
) {
|
||||
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).tick_fling(Instant::now()),
|
||||
None => false,
|
||||
})
|
||||
.await;
|
||||
if !still_scrolling {
|
||||
return;
|
||||
}
|
||||
tokio::time::sleep(Duration::from_millis(ANIM_STEP_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<Rsc>,
|
||||
redraw: &Arc<dyn RequestRedraw>,
|
||||
stream_tail: Vec<SeqEvent>,
|
||||
) -> (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<Rsc>,
|
||||
redraw: &Arc<dyn RequestRedraw>,
|
||||
platform: &Option<Arc<PlatformHandle>>,
|
||||
) {
|
||||
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<Rsc>,
|
||||
platform: &Option<Arc<PlatformHandle>>,
|
||||
ime_state: &Arc<Mutex<ImeState>>,
|
||||
) -> 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);
|
||||
}
|
||||
}
|
||||
@@ -1,11 +1,14 @@
|
||||
//! JNI calls the `bench` feature needs that go through the shell's own
|
||||
//! Java side rather than anything `iris`/`android-view` already wraps:
|
||||
//! `BatteryManager.getIntProperty(BATTERY_PROPERTY_CURRENT_NOW)` for the
|
||||
//! per-second battery sample, and `ClipboardManager.setPrimaryClip` for
|
||||
//! the "Copy report" control (P0's iris half, docs/RUST.md). Neither is
|
||||
//! part of `android_view::context`'s own `Context`/`Resources` wrappers
|
||||
//! (that file's own `// TODO: more methods?`), so this calls them
|
||||
//! directly rather than growing that crate's wrapper for two one-off
|
||||
//! per-second battery sample, `ClipboardManager.setPrimaryClip` for the
|
||||
//! "Copy report" control (P0's iris half, docs/RUST.md), and -- added for
|
||||
//! RUST.md's "Benchmark v2" -- `Display.getRefreshRate()` for the phase
|
||||
//! report's real late-frame budget and `InputMethodManager.
|
||||
//! showSoftInput`/`hideSoftInputFromWindow` for the keyboard phase. None
|
||||
//! of these are part of `android_view::context`'s own `Context`/
|
||||
//! `Resources` wrappers (that file's own `// TODO: more methods?`), so
|
||||
//! this calls them directly rather than growing that crate's wrapper for
|
||||
//! calls this crate alone needs.
|
||||
//!
|
||||
//! Holds its own `JavaVM` + `GlobalRef` to the view (handed in through
|
||||
@@ -131,4 +134,92 @@ impl PlatformHandle {
|
||||
.ok()?;
|
||||
Some(())
|
||||
}
|
||||
|
||||
/// The display's own refresh rate in Hz (`View::getDisplay()` ->
|
||||
/// `Display::getRefreshRate()`), for RUST.md's "Benchmark v2": late
|
||||
/// frames are judged against *this* device's real budget, not an
|
||||
/// assumed 60Hz -- a 90Hz or 120Hz phone would otherwise call frames
|
||||
/// "late" that met their own faster deadline. `None` if the view is
|
||||
/// not yet attached to a window (`getDisplay` returns `null`) or the
|
||||
/// platform reports a non-positive rate, which is not a real answer
|
||||
/// either.
|
||||
pub fn refresh_rate_hz(&self) -> Option<f32> {
|
||||
let mut guard = self.vm.attach_current_thread().ok()?;
|
||||
let env: &mut JNIEnv = &mut guard;
|
||||
let display = env
|
||||
.call_method(
|
||||
self.view.as_obj(),
|
||||
"getDisplay",
|
||||
"()Landroid/view/Display;",
|
||||
&[],
|
||||
)
|
||||
.ok()?
|
||||
.l()
|
||||
.ok()?;
|
||||
if display.is_null() {
|
||||
return None;
|
||||
}
|
||||
let rate = env
|
||||
.call_method(&display, "getRefreshRate", "()F", &[])
|
||||
.ok()?
|
||||
.f()
|
||||
.ok()?;
|
||||
if rate > 0.0 { Some(rate) } else { None }
|
||||
}
|
||||
|
||||
/// `InputMethodManager.showSoftInput(view, 0)` -- the keyboard phase's
|
||||
/// own show, called directly rather than through the focus-driven
|
||||
/// `pending_show_keyboard` path `android/view.rs` uses for a real tap,
|
||||
/// since RUST.md's "Benchmark v2" spec asks for this "through the
|
||||
/// shell's InputMethodManager" independent of focus state. `true` only
|
||||
/// if the platform itself reports the request succeeded -- whether the
|
||||
/// IME actually became visible is confirmed separately, from
|
||||
/// `on_insets_changed`, per UI_RULES.md ("never present an inferred
|
||||
/// value as a measured one").
|
||||
pub fn show_ime(&self) -> bool {
|
||||
self.try_toggle_ime(true).unwrap_or(false)
|
||||
}
|
||||
|
||||
/// `InputMethodManager.hideSoftInputFromWindow(windowToken, 0)`.
|
||||
pub fn hide_ime(&self) -> bool {
|
||||
self.try_toggle_ime(false).unwrap_or(false)
|
||||
}
|
||||
|
||||
fn try_toggle_ime(&self, show: bool) -> Option<bool> {
|
||||
let mut guard = self.vm.attach_current_thread().ok()?;
|
||||
let env: &mut JNIEnv = &mut guard;
|
||||
let context = self.context(env)?;
|
||||
let imm = self.system_service(env, &context, "input_method")?;
|
||||
if show {
|
||||
env.call_method(
|
||||
&imm,
|
||||
"showSoftInput",
|
||||
"(Landroid/view/View;I)Z",
|
||||
&[JValue::Object(self.view.as_obj()), JValue::Int(0)],
|
||||
)
|
||||
.ok()?
|
||||
.z()
|
||||
.ok()
|
||||
} else {
|
||||
let token = env
|
||||
.call_method(
|
||||
self.view.as_obj(),
|
||||
"getWindowToken",
|
||||
"()Landroid/os/IBinder;",
|
||||
&[],
|
||||
)
|
||||
.ok()?
|
||||
.l()
|
||||
.ok()?;
|
||||
env.call_method(
|
||||
&imm,
|
||||
"hideSoftInputFromWindow",
|
||||
"(Landroid/os/IBinder;I)Z",
|
||||
&[JValue::Object(&token), JValue::Int(0)],
|
||||
)
|
||||
.ok()?
|
||||
.z()
|
||||
.ok()
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -1,15 +1,87 @@
|
||||
use std::time::Duration;
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
/// The frame budget `dumpsys gfxinfo` also uses to call a frame "janky": the
|
||||
/// 60Hz vsync period. Kept as the same threshold so a percentage from this
|
||||
/// report and a percentage from `gfxinfo` mean the same thing.
|
||||
/// report and a percentage from `gfxinfo` mean the same thing. Only a
|
||||
/// fallback now that a caller can read the display's real refresh rate
|
||||
/// (`report_at_hz`/`mark_phase`'s callers) -- most devices are 60Hz, but a
|
||||
/// 90Hz or 120Hz phone judged against this constant would call every frame
|
||||
/// "late" that merely met its own, faster budget.
|
||||
pub const JANK_THRESHOLD: Duration = Duration::from_nanos(16_666_667);
|
||||
|
||||
/// Enough frames for several minutes of scrolling before the oldest ones
|
||||
/// start being overwritten -- the same "diagnostic, not a log" sizing
|
||||
/// `FrameStats.kt`'s `CAP` uses on the Compose side, chosen independently
|
||||
/// here since a `Duration` is smaller than the six `Long` arrays it keeps.
|
||||
const RING_CAPACITY: usize = 4096;
|
||||
/// Bumped from 4096 for RUST.md's "Benchmark v2": a fling+stream+type+
|
||||
/// keyboard run is ~6,500+ frames on the Compose side, comfortably under
|
||||
/// this so `phase_stats` never has to report a phase as partially evicted.
|
||||
const RING_CAPACITY: usize = 16384;
|
||||
|
||||
/// One `mark_phase` call: the wall-clock instant and the (0-based,
|
||||
/// never-reset-by-`reset`-except-at-`reset`-time) absolute frame index at
|
||||
/// which a phase began -- `phase_stats` slices `index_ring` against this to
|
||||
/// find which recorded samples belong to which phase, since the ring
|
||||
/// itself only keeps the most recent `RING_CAPACITY` samples' *values*,
|
||||
/// not which phase they were in.
|
||||
struct PhaseMark {
|
||||
name: String,
|
||||
start_index: u64,
|
||||
start_at: Instant,
|
||||
}
|
||||
|
||||
/// One phase's own slice of a report -- RUST.md's "Benchmark v2" spec's
|
||||
/// "per-phase blocks in `FrameReport`... frames, late count/percent...
|
||||
/// p50/p90/p99, worst, duration". `Display` matches the shape
|
||||
/// `docs/bench/compose-phone-v2-2026-09-06.md`'s report already uses, so
|
||||
/// the two apps' reports read the same way side by side.
|
||||
pub struct PhaseStats {
|
||||
pub name: String,
|
||||
/// How many frames were recorded during this phase in total -- may
|
||||
/// exceed `late + (samples counted)` if some of this phase's frames
|
||||
/// have since been evicted from the ring by a very long run; that
|
||||
/// case is named in the `Display` rather than silently under-counted.
|
||||
pub frames: u64,
|
||||
pub duration: Duration,
|
||||
pub late: u64,
|
||||
pub late_percent: f64,
|
||||
pub p50: Duration,
|
||||
pub p90: Duration,
|
||||
pub p99: Duration,
|
||||
pub worst: Duration,
|
||||
/// `false` if this phase's frame count exceeds how many samples of it
|
||||
/// are still in the ring -- the percentiles above are then computed
|
||||
/// over whatever survived, not the whole phase. UI_RULES.md: this is
|
||||
/// the "we don't fully know" state, named rather than folded silently
|
||||
/// into a number that looks exact.
|
||||
pub complete: bool,
|
||||
}
|
||||
|
||||
impl std::fmt::Display for PhaseStats {
|
||||
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
|
||||
writeln!(
|
||||
f,
|
||||
" {}: {} frames over {:.1}s{}",
|
||||
self.name,
|
||||
self.frames,
|
||||
self.duration.as_secs_f64(),
|
||||
if self.complete {
|
||||
""
|
||||
} else {
|
||||
" (ring evicted some of this phase)"
|
||||
},
|
||||
)?;
|
||||
writeln!(f, " late: {} ({:.1}%)", self.late, self.late_percent)?;
|
||||
writeln!(
|
||||
f,
|
||||
" total p50 {:.1}ms p90 {:.1}ms p99 {:.1}ms",
|
||||
self.p50.as_secs_f64() * 1000.0,
|
||||
self.p90.as_secs_f64() * 1000.0,
|
||||
self.p99.as_secs_f64() * 1000.0,
|
||||
)?;
|
||||
write!(f, " worst {:.1}ms", self.worst.as_secs_f64() * 1000.0)
|
||||
}
|
||||
}
|
||||
|
||||
/// A per-frame wall-time report iris keeps of itself, because `dumpsys
|
||||
/// gfxinfo` cannot see a `SurfaceView`'s own GPU-drawn frames at all
|
||||
@@ -41,6 +113,11 @@ pub struct FrameReport {
|
||||
/// "Where iris's frame time goes" CPU/GPU split, added 2026-09-05).
|
||||
/// `ring[i] - submit_ring[i]` is that frame's `redraw_to_submit` half.
|
||||
submit_ring: Box<[Duration; RING_CAPACITY]>,
|
||||
/// The absolute (0-based, since the last `reset`) frame index each
|
||||
/// `ring`/`submit_ring` slot's sample belongs to -- what `phase_stats`
|
||||
/// slices against `PhaseMark::start_index` to tell which recorded
|
||||
/// frames fall in which phase.
|
||||
index_ring: Box<[u64; RING_CAPACITY]>,
|
||||
/// How many of `ring`'s slots hold a real sample -- saturates at
|
||||
/// `RING_CAPACITY`, unlike `total_frames` below which keeps counting.
|
||||
len: usize,
|
||||
@@ -50,6 +127,12 @@ pub struct FrameReport {
|
||||
/// correct even once the ring itself only holds the most recent frames.
|
||||
total_frames: u64,
|
||||
janky_frames: u64,
|
||||
/// `mark_phase` calls since the last `reset`, oldest first -- see
|
||||
/// `phase_stats`. Empty on an ordinary run that never calls
|
||||
/// `mark_phase`, so `phase_stats` returns an empty `Vec` and a caller
|
||||
/// prints no "per phase:" section at all, matching RUST.md's "empty/
|
||||
/// absent on an ordinary 'Copy' press, which never marks a phase."
|
||||
phases: Vec<PhaseMark>,
|
||||
}
|
||||
|
||||
/// One resolved reading. `Display` is the log line both the "Frame report"
|
||||
@@ -107,10 +190,12 @@ impl FrameReport {
|
||||
Self {
|
||||
ring: Box::new([Duration::ZERO; RING_CAPACITY]),
|
||||
submit_ring: Box::new([Duration::ZERO; RING_CAPACITY]),
|
||||
index_ring: Box::new([0; RING_CAPACITY]),
|
||||
len: 0,
|
||||
pos: 0,
|
||||
total_frames: 0,
|
||||
janky_frames: 0,
|
||||
phases: Vec::new(),
|
||||
}
|
||||
}
|
||||
|
||||
@@ -131,6 +216,7 @@ impl FrameReport {
|
||||
pub fn record_split(&mut self, total: Duration, submit_to_present: Duration) {
|
||||
self.ring[self.pos] = total;
|
||||
self.submit_ring[self.pos] = submit_to_present;
|
||||
self.index_ring[self.pos] = self.total_frames;
|
||||
self.pos = (self.pos + 1) % RING_CAPACITY;
|
||||
self.len = (self.len + 1).min(RING_CAPACITY);
|
||||
self.total_frames += 1;
|
||||
@@ -142,12 +228,89 @@ impl FrameReport {
|
||||
/// Clears every counter and every sample -- what the "Reset frame
|
||||
/// report" control calls, so a report covers only what was scrolled
|
||||
/// after the button was pressed (the same reason `FrameStats.kt`'s
|
||||
/// `reset()` exists on the Compose side).
|
||||
/// `reset()` exists on the Compose side). Also clears every phase
|
||||
/// mark, so a fresh run starts with no "per phase:" section until it
|
||||
/// marks one of its own.
|
||||
pub fn reset(&mut self) {
|
||||
self.len = 0;
|
||||
self.pos = 0;
|
||||
self.total_frames = 0;
|
||||
self.janky_frames = 0;
|
||||
self.phases.clear();
|
||||
}
|
||||
|
||||
/// Marks the start of a named phase at the current moment -- every
|
||||
/// frame recorded from here until the next `mark_phase` (or `reset`)
|
||||
/// belongs to it. RUST.md's "Benchmark v2": a scripted bench run calls
|
||||
/// this once per phase (fling/stream/type/keyboard) so `phase_stats`
|
||||
/// can slice one whole run's frames by what was happening during each.
|
||||
pub fn mark_phase(&mut self, name: &str) {
|
||||
self.phases.push(PhaseMark {
|
||||
name: name.to_string(),
|
||||
start_index: self.total_frames,
|
||||
start_at: Instant::now(),
|
||||
});
|
||||
}
|
||||
|
||||
/// One [`PhaseStats`] per `mark_phase` call since the last `reset`,
|
||||
/// oldest first. `now` closes the last phase's wall-clock span (there
|
||||
/// is no "next phase" instant to use for it); `refresh_hz` is what
|
||||
/// each phase's own `late`/`late_percent` is judged against, read from
|
||||
/// the display rather than assumed -- RUST.md's "Benchmark v2": "late
|
||||
/// count/% against the display's refresh rate."
|
||||
pub fn phase_stats(&self, now: Instant, refresh_hz: f32) -> Vec<PhaseStats> {
|
||||
if self.phases.is_empty() || refresh_hz <= 0.0 {
|
||||
return Vec::new();
|
||||
}
|
||||
let budget = Duration::from_secs_f64(1.0 / refresh_hz as f64);
|
||||
self.phases
|
||||
.iter()
|
||||
.enumerate()
|
||||
.map(|(i, phase)| {
|
||||
let (end_index, end_at) = match self.phases.get(i + 1) {
|
||||
Some(next) => (next.start_index, next.start_at),
|
||||
None => (self.total_frames, now),
|
||||
};
|
||||
let frames = end_index.saturating_sub(phase.start_index);
|
||||
let mut samples: Vec<Duration> = (0..self.len)
|
||||
.filter(|&j| {
|
||||
let idx = self.index_ring[j];
|
||||
idx >= phase.start_index && idx < end_index
|
||||
})
|
||||
.map(|j| self.ring[j])
|
||||
.collect();
|
||||
let complete = samples.len() as u64 >= frames;
|
||||
if samples.is_empty() {
|
||||
return PhaseStats {
|
||||
name: phase.name.clone(),
|
||||
frames,
|
||||
duration: end_at.saturating_duration_since(phase.start_at),
|
||||
late: 0,
|
||||
late_percent: 0.0,
|
||||
p50: Duration::ZERO,
|
||||
p90: Duration::ZERO,
|
||||
p99: Duration::ZERO,
|
||||
worst: Duration::ZERO,
|
||||
complete,
|
||||
};
|
||||
}
|
||||
samples.sort_unstable();
|
||||
let pct = |p: usize| samples[(samples.len() * p / 100).min(samples.len() - 1)];
|
||||
let late = samples.iter().filter(|&&d| d > budget).count() as u64;
|
||||
PhaseStats {
|
||||
name: phase.name.clone(),
|
||||
frames,
|
||||
duration: end_at.saturating_duration_since(phase.start_at),
|
||||
late,
|
||||
late_percent: 100.0 * late as f64 / samples.len() as f64,
|
||||
p50: pct(50),
|
||||
p90: pct(90),
|
||||
p99: pct(99),
|
||||
worst: *samples.last().expect("checked not empty above"),
|
||||
complete,
|
||||
}
|
||||
})
|
||||
.collect()
|
||||
}
|
||||
|
||||
/// `None` if nothing has been recorded since the last reset -- the
|
||||
@@ -186,6 +349,28 @@ impl FrameReport {
|
||||
gpu_wait_p50: median(submit_samples),
|
||||
})
|
||||
}
|
||||
|
||||
/// `(late count, late percent)` over every sample still in the ring,
|
||||
/// judged against `refresh_hz`'s own frame budget rather than the
|
||||
/// fixed 60Hz `JANK_THRESHOLD` -- RUST.md's "Benchmark v2": "late
|
||||
/// count/% against the display's refresh rate... print 'at N Hz (X ms
|
||||
/// budget)' like Compose does." A separate method from `report()`
|
||||
/// rather than a parameter on it, so `report()`'s own `janky_percent`
|
||||
/// (and the exact-boundary test pinned to `JANK_THRESHOLD`) is
|
||||
/// unaffected for every existing caller that never measured a real
|
||||
/// refresh rate. `(0, 0.0)` with nothing recorded or a non-positive
|
||||
/// `refresh_hz`.
|
||||
pub fn late_at_hz(&self, refresh_hz: f32) -> (u64, f64) {
|
||||
if self.len == 0 || refresh_hz <= 0.0 {
|
||||
return (0, 0.0);
|
||||
}
|
||||
let budget = Duration::from_secs_f64(1.0 / refresh_hz as f64);
|
||||
let late = self.ring[..self.len]
|
||||
.iter()
|
||||
.filter(|&&d| d > budget)
|
||||
.count() as u64;
|
||||
(late, 100.0 * late as f64 / self.len as f64)
|
||||
}
|
||||
}
|
||||
|
||||
impl Default for FrameReport {
|
||||
@@ -296,4 +481,68 @@ mod tests {
|
||||
// same pattern here.
|
||||
assert!(stats.worst <= Duration::from_millis(5));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn no_marks_means_no_phases() {
|
||||
let mut r = FrameReport::new();
|
||||
r.record(Duration::from_millis(5));
|
||||
assert!(r.phase_stats(Instant::now(), 60.0).is_empty());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn phases_slice_frames_by_when_they_were_marked() {
|
||||
let mut r = FrameReport::new();
|
||||
r.mark_phase("a");
|
||||
for _ in 0..5 {
|
||||
r.record(Duration::from_millis(10)); // 10ms: late at 60Hz (16.7ms budget)... no, 10<16.7, not late
|
||||
}
|
||||
r.mark_phase("b");
|
||||
for _ in 0..3 {
|
||||
r.record(Duration::from_millis(20)); // 20ms: late at 60Hz
|
||||
}
|
||||
let now = Instant::now();
|
||||
let phases = r.phase_stats(now, 60.0);
|
||||
assert_eq!(phases.len(), 2);
|
||||
assert_eq!(phases[0].name, "a");
|
||||
assert_eq!(phases[0].frames, 5);
|
||||
assert_eq!(phases[0].late, 0);
|
||||
assert_eq!(phases[0].worst, Duration::from_millis(10));
|
||||
assert_eq!(phases[1].name, "b");
|
||||
assert_eq!(phases[1].frames, 3);
|
||||
assert_eq!(phases[1].late, 3);
|
||||
assert_eq!(phases[1].late_percent, 100.0);
|
||||
assert_eq!(phases[1].worst, Duration::from_millis(20));
|
||||
assert!(phases[0].complete);
|
||||
assert!(phases[1].complete);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_last_phase_runs_until_now() {
|
||||
let mut r = FrameReport::new();
|
||||
r.mark_phase("only");
|
||||
r.record(Duration::from_millis(1));
|
||||
std::thread::sleep(Duration::from_millis(20));
|
||||
let now = Instant::now();
|
||||
let phases = r.phase_stats(now, 60.0);
|
||||
assert_eq!(phases.len(), 1);
|
||||
assert!(phases[0].duration >= Duration::from_millis(20));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn reset_clears_phase_marks() {
|
||||
let mut r = FrameReport::new();
|
||||
r.mark_phase("a");
|
||||
r.record(Duration::from_millis(1));
|
||||
r.reset();
|
||||
assert!(r.phase_stats(Instant::now(), 60.0).is_empty());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn late_at_hz_uses_the_given_refresh_rate_not_the_fixed_60hz_constant() {
|
||||
let mut r = FrameReport::new();
|
||||
// 10ms is under 60Hz's 16.7ms budget but over 120Hz's 8.3ms one.
|
||||
r.record(Duration::from_millis(10));
|
||||
assert_eq!(r.late_at_hz(60.0), (0, 0.0));
|
||||
assert_eq!(r.late_at_hz(120.0), (1, 100.0));
|
||||
}
|
||||
}
|
||||
@@ -489,6 +489,24 @@ impl List {
|
||||
true
|
||||
}
|
||||
|
||||
/// The anchor's own row index and pixel offset, formatted the same
|
||||
/// shape Compose's `firstVisibleItemIndex`/`firstVisibleItemScrollOffset`
|
||||
/// report (`idx=N/off=Mpx`) -- what RUST.md's "Benchmark v2" fling
|
||||
/// phase reads before/after/between its fling runs so the two apps'
|
||||
/// travel can be compared directly. `more_before`/`more_after`
|
||||
/// sentinels print as `idx=more-before`/`idx=more-after` rather than
|
||||
/// leaking their internal `isize` representation; `idx=none` if the
|
||||
/// list has never drawn (no anchor yet -- e.g. right after
|
||||
/// `jump_to_end` and before the next frame runs `repair_anchor`).
|
||||
pub fn anchor_position_display(&self) -> String {
|
||||
match self.anchor {
|
||||
None => "idx=none".to_string(),
|
||||
Some(a) if a.slot == BEFORE_SLOT => "idx=more-before".to_string(),
|
||||
Some(a) if a.slot == AFTER_SLOT => "idx=more-after".to_string(),
|
||||
Some(a) => format!("idx={}/off={}px", a.slot, a.offset.round() as i64),
|
||||
}
|
||||
}
|
||||
|
||||
/// Snap to the newest content (last item, or the `more_after`
|
||||
/// sentinel if set), bottom-aligned to the viewport. O(1).
|
||||
pub fn jump_to_end(&mut self) {
|
||||
@@ -1455,4 +1473,22 @@ mod tests {
|
||||
first.top
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn anchor_position_display_before_any_draw_is_none() {
|
||||
let list = List::new(Axis::Y);
|
||||
assert_eq!(list.anchor_position_display(), "idx=none");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn anchor_position_display_reports_slot_and_offset() {
|
||||
let mut rsc = TestRsc {
|
||||
ui: UiData::default(),
|
||||
};
|
||||
let (list_weak, root, mut render) = build_flingable_list(&mut rsc);
|
||||
let _ = (&root, &mut render);
|
||||
let list_ref = rsc.ui.widgets.get(&list_weak).unwrap();
|
||||
assert!(list_ref.anchor_position_display().starts_with("idx="));
|
||||
assert!(!list_ref.anchor_position_display().contains("none"));
|
||||
}
|
||||
}
|
||||
Reference in new issue
Block a user