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 d8ee44d..ea59c9a 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 @@ -139,13 +139,18 @@ impl i_slint_core::platform::Platform for AndroidPlatform { // alive makes poll_events wake at each display refresh instead. let animating = self.window.window.has_active_animations() || stg::pointer_recently_active(); - vsync.set_animating(animating); - if animating { - // When animating (scrolling/flinging), cap the poll timeout to 6ms - // as a safety net in case a vsync wake is lost. Rendering still - // only happens when `pending_redraw` is set (content actually - // changed) — we do NOT force a redraw here, which would waste - // GPU re-rendering an unchanged scene on every wake. + // Push (animating, dirty) to the vsync driver: the Choreographer + // callback chain self-sustains while animating OR dirty + // (vsync.rs) — the dirty leg is what keeps flings alive after + // pointer inactivity expires the `animating` window. + let dirty = self.window.pending_redraw.get(); + vsync.set_state(animating, dirty); + if animating || dirty { + // When animating (scrolling/flinging) or dirty, cap the poll + // timeout to 6ms as a safety net in case a vsync wake is + // lost (chain break self-heals within one backstop cycle). + // Rendering still only happens on wakes (locked) or when + // `pending_redraw` is set (unlocked). let frame_duration = Duration::from_millis(6); timeout = Some(timeout.map_or(frame_duration, |x| x.min(frame_duration))); } @@ -318,7 +323,10 @@ impl i_slint_core::platform::Platform for AndroidPlatform { if __p != 0 && __last != 0 && __sw >= __sn + 2 && stg::IT_ON.load(std::sync::atomic::Ordering::Relaxed) { - stg::log_miss(__sw - __sn - 1, saw_wake, __now_ns); + stg::log_miss(__sw - __sn - 1, saw_wake, __now_ns, + __sw, __sn, + __now_ns.saturating_sub(__e) / 1000, + __now_ns.saturating_sub(__last) / 1000); } let __accept = saw_wake && (__p == 0 || __sw > __sn); if __accept { @@ -386,6 +394,28 @@ impl i_slint_core::platform::Platform for AndroidPlatform { self.window.do_render()?; } prev_locked = locked; + // Miss forensics (CONDITIONAL — 2026-07-09): the per-iteration + // /proc read was itself a confounder (procfs reads cost tens of + // µs on the UI thread; with render completion near the slot + // boundary that pushed the present phase across it — 10x worse + // drops/doubles measured). Sample only around SLOW iterations + // (>5 ms wall): those are exactly the miss candidates, and the + // common path pays nothing. + let __iter_wall = stg::now_us().saturating_sub(t_start); + let (__vsw, __nvol): + (u64, u64) = if __iter_wall > 5_000 && stg::IT_ON.load(std::sync::atomic::Ordering::Relaxed) + { + // Delta against the rolling baseline (previous slow sample). + let c = stg::ctxsw_sample(); + let pv = stg::CTX_PREV_V.load(std::sync::atomic::Ordering::Relaxed); + let pn = stg::CTX_PREV_NV.load(std::sync::atomic::Ordering::Relaxed); + let first = !stg::CTX_SAMPLED.swap(true, std::sync::atomic::Ordering::Relaxed); + stg::CTX_PREV_V.store(c.0, std::sync::atomic::Ordering::Relaxed); + stg::CTX_PREV_NV.store(c.1, std::sync::atomic::Ordering::Relaxed); + if first { (0, 0) } else { (c.0.saturating_sub(pv), c.1.saturating_sub(pn)) } + } else { + (0, 0) + }; if stg::IT_ON.load(std::sync::atomic::Ordering::Relaxed) { let first_ev = stg::S_FIRST_EV.load(std::sync::atomic::Ordering::Relaxed); let lv2 = stg::lv_snapshot(); @@ -408,6 +438,8 @@ impl i_slint_core::platform::Platform for AndroidPlatform { (locked, saw_wake, pr_before, do_render), __poll_cpu, __render_cpu, + __vsw, + __nvol, ); } } 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 3a8c9b9..21e208d 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 @@ -178,8 +178,59 @@ pub fn log_slow_event(name: &str, us: u64, cpu_us: u64) { /// This line is the missing evidence for the 20-100 ms stall slots: /// saw_wake=true ⇒ the previous slots' wakes were LOST (eventfd/waker) /// nowake context + slow poll/ev in the preceding IT line ⇒ loop blocked -pub fn log_miss(slots: i128, saw_wake: bool, now_ns: u64) { - log::info!("MISS mon={} slots={} nowake={}", now_ns, slots, if saw_wake { 1 } else { 0 }); +/// sw/sn = the wake's and last-render's edge-grid slot indices; eage_ms = +/// how stale the edge reference (VSYNC_EDGE_NS) is (ms); lastage_ms = how +/// old the last render start is (ms). Diagnosis from these: +/// sw <= sn with eage small ⇒ guard arithmetic (slot grid) bug +/// sw > sn but saw_wake=0 ⇒ no Wake arrived (chain dead / eventfd lost) +/// eage large (>> 2 slots) ⇒ Choreographer callbacks stalled; the edge +/// grid is stale and slot math is garbage — +/// the callback CHAIN is the failure +/// lastage huge + saw_wake=1 ⇒ loop was stuck (see IT line / ctxsw) +pub fn log_miss(slots: i128, saw_wake: bool, now_ns: u64, sw: i128, sn: i128, + eage_us: u64, lastage_us: u64) { + log::info!("MISS mon={} slots={} nowake={} sw={} sn={} eage={}us lastage={}us", + now_ns, slots, if saw_wake { 1 } else { 0 }, sw, sn, eage_us, lastage_us); +} + +/// Context-switch counters for the UI (main) thread, sampled from +/// /proc/self/task//stat (main thread: pid == tid). Called twice per +/// iteration (start/end); the delta attributes the iteration: +/// vsw high, pcpu low ⇒ thread VOLUNTARILY blocked (epoll with no wake +/// byte, futex/lock, IO, binder — "waiting on +/// something") +/// nvol high, pcpu low ⇒ SCHEDULER descheduled it (priority/pressure) +/// pcpu ≈ wall ⇒ ran on CPU (Skia/driver work) +/// Rolling baseline of the last ctxsw sample (CONDITIONAL sampling — see +/// lib.rs): the delta reported on a slow iteration spans [previous slow +/// iteration .. this slow iteration]. Coarse, but enough to separate +/// voluntary-blocking from involuntary-descheduling windows. +pub static CTX_PREV_V: AtomicU64 = AtomicU64::new(0); +pub static CTX_PREV_NV: AtomicU64 = AtomicU64::new(0); +pub static CTX_SAMPLED: AtomicBool = AtomicBool::new(false); + +pub fn ctxsw_sample() -> (u64, u64) { + use std::io::{Read, Seek, SeekFrom}; + static F: std::sync::Mutex> = std::sync::Mutex::new(None); + let mut g = match F.lock() { Ok(g) => g, Err(_) => return (0, 0) }; + if g.is_none() { + let p = format!("/proc/self/task/{}/stat", std::process::id()); + *g = std::fs::File::open(p).ok(); + } + let f = match g.as_mut() { Some(f) => f, None => return (0, 0) }; + let _ = f.seek(SeekFrom::Start(0)); + let mut buf = [0u8; 600]; + let n = match f.read(&mut buf) { Ok(n) => n, Err(_) => return (0, 0) }; + let s = String::from_utf8_lossy(&buf[..n]); + let after = match s.rfind(')') { Some(i) => &s[i + 2..], None => return (0, 0) }; + let toks: Vec<&str> = after.split_whitespace().collect(); + // after ')': tok[0] = field 3 (state) … field 40 (voluntary) = tok[37], + // field 41 (nonvoluntary) = tok[38] + match (toks.get(37).and_then(|t| t.parse().ok()), + toks.get(38).and_then(|t| t.parse().ok())) { + (Some(v), Some(nv)) => (v, nv), + _ => (0, 0), + } } /// Jank-hunt: total `invoke_from_event_loop` pushes (INVK n=..). @@ -254,6 +305,8 @@ pub fn log_iter( dec: (bool, bool, bool, bool), poll_cpu_us: u64, render_cpu_us: u64, + vsw: u64, + nvol: 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 @@ -262,10 +315,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={}/{}/{}/{} pcpu={}us rcpu={}us", + "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 rcpu={}us vsw={} nvol={}", 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, poll_cpu_us, render_cpu_us + dec.0 as u8, dec.1 as u8, dec.2 as u8, dec.3 as u8, poll_cpu_us, render_cpu_us, vsw, nvol ); } 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 647a9f0..04c7e9e 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 @@ -47,6 +47,16 @@ unsafe impl Sync for Shared {} #[derive(Default)] struct State { animating: bool, + /// Window is dirty (pending_redraw). The Choreographer callback chain + /// re-posts while `animating || dirty` (2026-07-09): gating on + /// `animating` alone let the chain die during flings (pointer + /// inactivity >200 ms) and on any `has_active_animations` flicker — + /// with the early waker disabled the loop then froze until the next + /// input event (measured: 30 frames in 4 s of drag, then silence). + /// `set_state` is called by the main loop on EVERY iteration, so the + /// dirty mirror can be at most one iteration (≈8 ms) stale — the 6 ms + /// poll backstop for dirty windows bounds the damage of a chain break. + dirty: bool, quit: bool, callback_posted: bool, } @@ -102,20 +112,24 @@ impl VsyncDriver { self.shared.driving.load(Ordering::Acquire) } - pub fn set_animating(&self, animating: bool) { + /// Push (animating, dirty) into the driver every main-loop iteration. + /// The vsync thread re-posts the first Choreographer callback, and + /// `frame_callback` re-posts the chain, while `animating || dirty`. + pub fn set_state(&self, animating: bool, dirty: bool) { let mut state = self.shared.state.lock().unwrap(); - if state.animating != animating { - state.animating = animating; + let was_active = state.animating || state.dirty; + let now_active = animating || dirty; + state.animating = animating; + state.dirty = dirty; + if !was_active && now_active { drop(state); - if animating { - // Wake the vsync thread: it may be parked in `poll_once` (the - // Choreographer queue drained once the previous animation's - // self-sustaining callback chain ended). Waking the looper is - // what makes it re-check `state.animating` and post the first - // frame callback for this new animation. - if let Some(looper) = self.shared.looper.lock().unwrap().as_ref() { - looper.wake(); - } + // Wake the vsync thread: it may be parked in `poll_once` (the + // Choreographer queue drained once the previous active phase's + // self-sustaining callback chain ended). Waking the looper is + // what makes it re-check the state and post the first frame + // callback for this new phase. + if let Some(looper) = self.shared.looper.lock().unwrap().as_ref() { + looper.wake(); } self.shared.cond.notify_one(); } @@ -197,7 +211,19 @@ fn early_waker_thread(shared: Arc) { // 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. - if landed <= 1_000_000 { + // + // EW_ON (2026-07-09) now gates the WAKE itself, not just the EW log. + // The waker was built on the refuted "callback 3-6 ms late" model; + // the Choreographer fires at edge+0.52 ms (measured) and is the + // single correct wake source. Two wake sources race the slot guard + // and each renders at its own phase — the measured render-phase + // wander (-4..+4 ms) that turned a 120 Hz stream into 12-17 ms + // gaps (drops) and 4-6 ms gaps (doubles). With the Choreographer + // alone, the render phase is pinned to edge+~0.5-1.0 ms. + if landed <= 1_000_000 + && i_slint_renderer_skia::wgpu_30_surface::vkprobe::EW_ON + .load(Ordering::Relaxed) + { waker.wake(); } } @@ -250,7 +276,7 @@ unsafe extern "C" fn frame_callback( } let mut state = shared.state.lock().unwrap(); - if state.animating && !state.quit { + if (state.animating || state.dirty) && !state.quit { unsafe { ffi::AChoreographer_postFrameCallback( shared.choreographer, @@ -295,7 +321,7 @@ fn vsync_thread(shared: Arc) { // 4…) and each vsync fires N callbacks → N main-loop wakes with N // unbounded. That was the ~1600 iters/s busy-spin. See // docs/BUGS/scroll-jank-120hz.md. - if state.animating && !state.callback_posted { + if (state.animating || state.dirty) && !state.callback_posted { state.callback_posted = true; unsafe { ffi::AChoreographer_postFrameCallback( diff --git a/vendor/i-slint-renderer-skia/wgpu_30_surface.rs b/vendor/i-slint-renderer-skia/wgpu_30_surface.rs index ff715fd..94a8161 100644 --- a/vendor/i-slint-renderer-skia/wgpu_30_surface.rs +++ b/vendor/i-slint-renderer-skia/wgpu_30_surface.rs @@ -601,12 +601,18 @@ impl crate::Surface for WGPUSurface { cb(); } let t_pre = vkprobe::now_us(); + // precpu = CPU time inside Queue::present (vkprobe::thread_cpu_ns + // exists already). pre_us≫precpu ⇒ present BLOCKED (binder/fence + // wait on the driver/SF — the "Android API call" contention); + // pre_us≈precpu ⇒ CPU-bound present. + let __pc0 = vkprobe::thread_cpu_ns(); self.wgpu.queue.present(pf); let pre_us = vkprobe::now_us().saturating_sub(t_pre); + let precpu_us = vkprobe::thread_cpu_ns().saturating_sub(__pc0) / 1000; vkprobe::report("PRE", &vkprobe::PRE, pre_us); let mon = vkprobe::monotonic_ns(); if mon > 0 { - log::info!("PRES f={} mon={} pre_us={}", pf_idx, mon, pre_us); + log::info!("PRES f={} mon={} pre_us={} precpu={}us", pf_idx, mon, pre_us, precpu_us); } } let __cpu0 = vkprobe::thread_cpu_ns();