Fling: the vsync clock, the frame ask, and a report that can say what it measured

Iris, from her phone: "some stuttering when flinging in particular.
Harder to notice with my finger directly moving the scroll." Her fling
phase was 103fps on a 120Hz screen at p50 6.3ms.

Two of the four things found are corrections to the instrument, not the
renderer. The swapchain acquire -- `get_current_texture`, which *blocks*
until the compositor frees an image -- was inside the span the report
called iris's CPU work, so a fling comfortably ahead of the display read
as milliseconds of being slow. A frame is now three measured parts
(`FrameParts`: build, acquire, submit), per phase as well as per run. And
nothing could say a frame was never *produced*: `late` counts frames that
cost too much, which a reader does not see, while a frame that never
happens leaves the last one up for two refreshes, which is the stutter.
`PhaseStats::missed` counts vsyncs nothing was drawn for. It closes on
the emulator: 1548 frames + 452 missed over 33.0s at 60Hz is 1980
vsyncs.

The other two are the frame loop. `Choreographer.postFrameCallback`
schedules for the next vsync after the call, and iris asked at the *end*
of the callback -- so any frame whose work ran past the boundary
registered too late and got the vsync after, one frame over budget
silently costing a second. It is asked for immediately after
`tick_animations` now, on both backends. And the fling was advanced on
`Instant::now()` rather than the vsync `do_frame` carries: frames are
presented on an even cadence whatever clock computes them, so sampling
the spline at "whenever the callback ran" moves the content unevenly with
no frame late enough to appear in any report -- and a drag never had it,
which is the asymmetry Iris described. `PointerClock` is `DeviceClock`
and the view keeps one, anchored by whichever of a touch or a frame comes
first, so a fling is advanced on the clock its velocity was measured on.

`opt-level` for the Android release build goes from "s" to 3. The table
in RUST.md picked "s" on bytes alone; over the same warm fling eight
times iris's own per-frame work is p90 0.15ms/p99 0.42ms at "s" against
p90 0.09ms/p99 0.26ms at 3, for 1.8 MB of arm64 APK.

`app-rust/tests/fling_profile.rs` is the rig that established what a
fling frame actually costs and is kept for next time (Iris: "please keep
the profiling rig around for future use"): only one frame in six lays
anything out, and the multi-millisecond spikes are all first-pass.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

app-rust/Cargo.toml

@@ -111,7 +111,17 @@ panic = "abort"
 strip = true
 lto = "fat"
 codegen-units = 1
-opt-level = "s"
+# **Speed, not size** (2026-09-09). This was `"s"`, chosen when the
+# question was why the APK was double the Compose one -- but that was
+# measured in bytes only, and `"s"` costs the loop vectorisation and
+# inlining a renderer runs on. Measured with
+# `app-rust/tests/fling_profile.rs`, the same warm fling eight times over:
+# iris's own per-frame work is p90 0.15ms / p99 0.42ms at `"s"` and
+# p90 0.09ms / p99 0.26ms at `3`, so about a third of the CPU half of a
+# scrolling frame was being paid for 1.9 MB of download. The same
+# argument the table in docs/RUST.md gives for refusing `"z"`, applied one
+# level further up.
+opt-level = 3
 
 [profile.android-dev]
 inherits = "dev"

app-rust/src/android/bench_client.rs

@@ -821,7 +821,8 @@ impl BenchClient {
                         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",
+                             p99 {:.1}ms\n  worst {:.1}ms\n  build_p50 {:.1}ms  acquire_p50 \
+                             {:.1}ms  submit_p50 {:.1}ms",
                             stats.total_frames,
                             total_seconds,
                             refresh_hz,
@@ -831,6 +832,7 @@ impl BenchClient {
                             stats.p99.as_secs_f64() * 1000.0,
                             stats.worst.as_secs_f64() * 1000.0,
                             stats.cpu_p50.as_secs_f64() * 1000.0,
+                            stats.acquire_p50.as_secs_f64() * 1000.0,
                             stats.gpu_wait_p50.as_secs_f64() * 1000.0,
                         )
                     }

app-rust/tests/fling_profile.rs

@@ -0,0 +1,121 @@
+//! A profiling run rather than a test: what a fling frame costs on the
+//! CPU, at layer 1 (docs/RUST.md's "Three test layers") -- the real
+//! transcript screen over the real bench fixture, with no window, no
+//! compositor and no GPU, on a clock this file owns. It exists so "the
+//! fling stutters" can be attributed rather than guessed at, and it is
+//! kept between investigations rather than rewritten each time (Iris,
+//! 2026-09-09: "please keep the profiling rig around for future use").
+//!
+//!     cargo test --release --test fling_profile -- --ignored --nocapture
+//!
+//! `#[ignore]`d because it asserts nothing -- it prints a distribution,
+//! so `run-tests.sh` neither runs it nor can fail on it. **Release, or
+//! the numbers mean nothing**: layout is dominated by text shaping, which
+//! is an order of magnitude slower unoptimised.
+//!
+//! What it cannot answer: anything about the GPU, the present queue, or
+//! the phone's own clock. It measures the CPU half of a frame, which is
+//! where `cpu_p50` in a phone bench report comes from.
+
+use ai_app::ui::fixture::{PHONE_FRAME_MS, PHONE_SCALE, phone_size};
+use iris::harness::{Harness, TouchScript};
+use iris::prelude::*;
+use std::time::{Duration, Instant};
+
+/// Passes over the same content, alternating direction. More than two
+/// because the question the rig was built for is whether a frame's cost
+/// is first-time work (which the first pass pays and the rest do not) or
+/// work repeated every time a row comes back on screen.
+const PASSES: usize = 8;
+/// The velocity `bench_client.rs`'s fling phase uses, so a number here
+/// and a number in a phone report describe the same gesture.
+const VELOCITY: f32 = 12_000.0;
+/// A fling settles on the spline's own schedule (~2s at this velocity);
+/// this only stops a pass that somehow never settles from running away.
+const PASS_CAP_MS: u64 = 4_000;
+
+fn pct(sorted: &[Duration], p: f64) -> f64 {
+    let i = ((sorted.len() as f64 - 1.0) * p).round() as usize;
+    sorted[i].as_secs_f64() * 1000.0
+}
+
+fn summarise(name: &str, samples: &[Duration]) {
+    let mut v = samples.to_vec();
+    v.sort();
+    let over_budget = v
+        .iter()
+        .filter(|d| **d > Duration::from_micros(8_333))
+        .count();
+    println!(
+        "  {name:16} n={:<5} p50 {:.2}ms  p90 {:.2}ms  p99 {:.2}ms  worst {:.2}ms  \
+         over-8.3ms {over_budget}",
+        v.len(),
+        pct(&v, 0.5),
+        pct(&v, 0.9),
+        pct(&v, 0.99),
+        pct(&v, 1.0),
+    );
+}
+
+#[test]
+#[ignore]
+fn what_a_fling_frame_costs() {
+    let mut h = Harness::new(phone_size(), PHONE_SCALE);
+    let opened = ai_app::ui::fixture::open(&mut h.rsc, &mut h.state).expect("the fixture folds");
+    h.frame(0);
+    h.frame(PHONE_FRAME_MS);
+
+    // The recorded flick first, so the velocity a real finger produces is
+    // in the log beside the scripted passes below.
+    let flick = TouchScript::parse(include_str!("../touch/flick-120hz.touch")).unwrap();
+    h.replay(&flick);
+    println!(
+        "recorded flick released at {:?}px/s; scripted passes run at {VELOCITY}px/s",
+        (opened.screen.list)(&mut h.rsc).fling_velocity(),
+    );
+
+    let mut t = flick.end_ms();
+    let mut all_frames = Vec::new();
+    let mut all_layouts = Vec::new();
+    for pass in 0..PASSES {
+        // Away from the newest end on the even passes and back on the
+        // odd ones, the same out-and-back the bench's fling phase drives.
+        let velocity = if pass % 2 == 0 { VELOCITY } else { -VELOCITY };
+        let list = (opened.screen.list)(&mut h.rsc);
+        list.fling(velocity);
+        let id = opened.screen.list.id();
+        h.rsc.ui.animate(id);
+
+        let mut frames = Vec::new();
+        let mut layouts = Vec::new();
+        let end = t + PASS_CAP_MS;
+        while t <= end {
+            let at = Instant::now();
+            h.frame(t);
+            frames.push(at.elapsed());
+            layouts.push(h.render.last_layout_duration());
+            t += PHONE_FRAME_MS;
+            if !(opened.screen.list)(&mut h.rsc).is_scrolling() {
+                break;
+            }
+        }
+        let laid_out = layouts
+            .iter()
+            .filter(|d| **d > Duration::from_micros(20))
+            .count();
+        println!(
+            "pass {pass} ({}): {} frames, {laid_out} did layout",
+            if velocity > 0.0 { "out " } else { "back" },
+            frames.len(),
+        );
+        summarise("frame", &frames);
+        all_frames.extend(frames);
+        all_layouts.extend(layouts);
+        // A moment at rest between passes, as a finger would leave.
+        t += 200;
+    }
+
+    println!("\nall {PASSES} passes, primitives={}", h.render.active_primitive_count());
+    summarise("frame", &all_frames);
+    summarise("layout", &all_layouts);
+}