diff --git a/docs/BUGS/hypotheses-120hz.md b/docs/BUGS/hypotheses-120hz.md new file mode 100644 index 0000000..54687f3 --- /dev/null +++ b/docs/BUGS/hypotheses-120hz.md @@ -0,0 +1,42 @@ +# 120 Hz zero-jank campaign — hypothesis log + +Target: sltest (minimal 100-row grid, no textures) on the phone's Mali G715. +Definition of ZERO JANK (measured from PRES mon= + VSYNC ftn= lines): + 1. no display-slot skip: for consecutive presents, slot_index(n+1) == slot_index(n)+1 (100%) + 2. no same-slot double: two presents never land in the same display slot + 3. phase stable: present phase within its slot varies < 0.5 ms +Test: 2x `input swipe 640 1900 640 900 4000` (slow drags) + fling, ~10 s. +A "burst" = consecutive presents with gaps < 20 ms; evaluate inside bursts only. + +## Hypotheses (order = priority) + +- H6 [sltest confound]: sltest FileLogger is blocking (flush per line) on the + render path (PRES/STG/IT at ~240 lines/s). + FIX: non-blocking drain-thread logger. TEST: rebuild, re-measure baseline. +- H1: early waker misses edges (thread descheduled / nanosleep jitter) → + render starts late (edge+5 late wake wins) → present phase bimodal. + TEST: render-start phase histogram vs edges; early-wake hit rate. +- H2: Skia render core variance → present phase jitter. + TEST: VK SKD distribution in sltest (trivial scene, expect <1.5 ms). +- H3: wgpu/Mali submit+present latency variance (CLR/SKF/ORD/PRE). + TEST: VK PRE / CLR / SKF distributions in sltest. +- H4: event-loop overhead (timers, change tracker, spin iterations) eats the + slot budget. + TEST: IT poll/timers/ev/fe distributions; iters/s during scroll. +- H5: CPU scheduling of the UI thread (deschedule mid-slot, core migration, + frequency). + TEST: wall vs CPU split for the render window (vkprobe thread_cpu_ns). +- H7 [method confound]: adb `input swipe` motion is bursty (~20-60 Hz) → + grid movement itself is non-uniform regardless of render cadence. + TEST: pointer-location overlay + user finger, later. + +## Rules +- One hypothesis per build; keep the change minimal; measure before/after + with the identical test; record numbers here. +- A hypothesis is RULED OUT only when the measurement it predicts is absent + (not "the fix didn't help"). +- Phone hygiene before each run: clean task (sz=1), ResumedActivity, + dismiss 16KB dialog (sltest is debuggable), record log byte offsets. + +## Results +(append below) diff --git a/vendor/i-slint-backend-android-activity-1.18.1/lib.rs b/vendor/i-slint-backend-android-activity-1.18.1/lib.rs index a0eb364..5a7a840 100644 --- a/vendor/i-slint-backend-android-activity-1.18.1/lib.rs +++ b/vendor/i-slint-backend-android-activity-1.18.1/lib.rs @@ -201,6 +201,11 @@ impl i_slint_core::platform::Platform for AndroidPlatform { // push the present past the ~5.5 ms compositor deadline → every // frame shown one vsync late → effective 60 Hz + judder). let mut saw_wake = false; + // H5 (hypotheses-120hz.md): CPU time inside poll_events. wall≫cpu + // ⇒ the UI thread slept/descheduled while the wake byte was + // pending (epoll not woken, or the thread lost the CPU); wall≈cpu + // ⇒ the loop spun inside ALooper. + let __cpu_p0 = stg::thread_cpu_us(); self.app.poll_events(timeout, |e| { if matches!(e, PollEvent::Wake) { saw_wake = true; @@ -248,6 +253,7 @@ impl i_slint_core::platform::Platform for AndroidPlatform { } }); let t_poll1 = stg::now_us(); + let __poll_cpu = stg::thread_cpu_us().saturating_sub(__cpu_p0); let lv1 = stg::lv_snapshot(); // Unconditionally update timers and animations on every event-loop wakeup @@ -390,6 +396,7 @@ impl i_slint_core::platform::Platform for AndroidPlatform { stg::timeout_snapshot(), stg::wake_snapshot(), (locked, saw_wake, pr_before, do_render), + __poll_cpu, ); } } diff --git a/vendor/i-slint-backend-android-activity-1.18.1/stg.rs b/vendor/i-slint-backend-android-activity-1.18.1/stg.rs index 3658651..bba363f 100644 --- a/vendor/i-slint-backend-android-activity-1.18.1/stg.rs +++ b/vendor/i-slint-backend-android-activity-1.18.1/stg.rs @@ -242,6 +242,7 @@ pub fn log_iter( tocls: (u64, u64, u64), wk: (u64, u64, u64), dec: (bool, bool, bool, bool), + poll_cpu_us: u64, ) { // Jank-hunt fix: emit through the log facade (nblog) instead of a private // BufWriter — two independent buffers appending to the same file made IT @@ -250,10 +251,10 @@ pub fn log_iter( let live_rows = i_slint_core::model::repeater::LV_LIVE_ROWS .load(std::sync::atomic::Ordering::Relaxed); log::info!( - "IT {} poll={}us nev={} fe={}us timers={}us ev={}us render={}us anim={} to={}ms lv1={}/{} e={}/{}/{} ent={}/{} lv2={}/{} flk={}/{} inb={}/{} toc={}/{}/{} wk={}/{}/{} live={} dec={}/{}/{}/{}", + "IT {} poll={}us nev={} fe={}us timers={}us ev={}us render={}us anim={} to={}ms lv1={}/{} e={}/{}/{} ent={}/{} lv2={}/{} flk={}/{} inb={}/{} toc={}/{}/{} wk={}/{}/{} live={} dec={}/{}/{}/{} pcpu={}us", start_us, poll_us, nev, first_ev_us, timer_us, event_us, render_us, animating as u8, timeout_ms, lv1.0, lv1.1, lv1.2, lv1.3, lv1.4, lv1.5, lv1.6, lv2.0, lv2.1, flk.0, flk.1, inp.0, inp.2, tocls.0, tocls.1, tocls.2, wk.0, wk.1, wk.2, live_rows, - dec.0 as u8, dec.1 as u8, dec.2 as u8, dec.3 as u8 + dec.0 as u8, dec.1 as u8, dec.2 as u8, dec.3 as u8, poll_cpu_us ); } diff --git a/vendor/i-slint-backend-android-activity-1.18.1/vsync.rs b/vendor/i-slint-backend-android-activity-1.18.1/vsync.rs index 0a1c5c4..647a9f0 100644 --- a/vendor/i-slint-backend-android-activity-1.18.1/vsync.rs +++ b/vendor/i-slint-backend-android-activity-1.18.1/vsync.rs @@ -184,6 +184,16 @@ fn early_waker_thread(shared: Arc) { } let landed = i_slint_renderer_skia::wgpu_30_surface::vkprobe::monotonic_ns() .saturating_sub(target); + // WAKE PROBE: log every attempt (120/s, non-blocking logger) so we + // can see the nanosleep landing distribution: `land` is ns relative + // to the edge target (negative = early). H1 (hypotheses-120hz.md): + // if land is systematically > +1 ms the waker skips every wake and + // the late Choreographer wake (~edge+5) wins every slot. + if i_slint_renderer_skia::wgpu_30_surface::vkprobe::EW_ON + .load(Ordering::Relaxed) + { + log::info!("EW land={}ms", (landed as i64 - 800_000) / 1000); + } // Wake only if we landed within ~1 ms of the edge. If we overshot // (CPU starvation), the Choreographer's late wake (~5 ms after the // edge) covers the frame instead. diff --git a/vendor/i-slint-renderer-skia/wgpu_30_surface.rs b/vendor/i-slint-renderer-skia/wgpu_30_surface.rs index 4e924cf..ff715fd 100644 --- a/vendor/i-slint-renderer-skia/wgpu_30_surface.rs +++ b/vendor/i-slint-renderer-skia/wgpu_30_surface.rs @@ -89,6 +89,9 @@ pub mod vkprobe { std::sync::atomic::AtomicBool::new(false); /// Microseconds the most recent `present_gate()` slept (0 = no sleep). pub static GATE_US: AtomicU64 = AtomicU64::new(0); + /// WAKE PROBE: log every early-waker attempt (EW lines) — H1 check. + pub static EW_ON: std::sync::atomic::AtomicBool = + std::sync::atomic::AtomicBool::new(false); /// CLOCK_MONOTONIC ns when the last vsync-wake (locked) render STARTED. /// The event loop uses it to skip a second wake (e.g. the Choreographer's /// late fallback wake arriving ~5 ms after the early-waker's edge wake