Merge remote-tracking branch 'origin/rustify' into worktree-agent-a9002910a315fe719

iris/core/src/render/frame_report.rs

@@ -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));
+    }
 }