gallery/docs/BUGS/scroll-jank-120hz.md
Greg Pomerantz 2f4768f354 Fix 120Hz scroll jank end-to-end: render-ahead present + full-cache eviction off the UI thread
Three root causes, all fixed and verified on the Pixel 9 Pro:

1. Present phase (backend + renderer): VSYNC_LOCKED_RENDER defers the
   render to the vsync wake; RENDER_AHEAD presents the previous frame at
   the start of render() (phase = wake + ~1.1 ms) and holds the new
   frame one slot. Crash fix: a held wgpu frame must be PRESENTED, never
   merely dropped, before the next acquire (AlreadyAcquired panic at
   launch otherwise); discard_pending_frame presents too.

2. Full-res prefetch churn (src/lib.rs): the 8-slot full cache cycled
   through a ~20-cell viewport forever (137 decodes/20 s) and each
   eviction free()'d a 50 MB Vec on the UI thread (20-52 ms CPU spikes,
   ~7/s = the residual SLOWEV NonMain jank). Fix: 60 s tombstone
   cooldown on evicted paths (idle prefetch skips, urgent tap bypasses)
   + off-thread reaper for the freed blobs (insert: 21 ms -> 4 us).

3. (earlier) Skia final flush + Mailbox present mode (vendor, M3).

Instrumentation (all behind --features perf): OTHR/INVK/INVK_TAG/FLCK
lines for cross-thread closure timing and push-site tagging.

Warm measured swipe, 8580-file grid: cadence median 8.33 ms (exact
120 Hz), p99 15.5 ms, 5/552 gaps >16.7 ms (0.9%, max 28.3 ms, zero
>33 ms); PRES phase median ~994 us, zero late frames. Docs updated
(docs/BUGS/scroll-jank-120hz.md, full scorecard + line reference).

Also: vendored i-slint-core + wgpu-hal (vkshim interposition patch),
vkshim profiling tooling, backend made a non-optional dep, debuggable
flag for simpleperf (REMOVE before shipping).
2026-10-30 02:49:23 -04:00

7.6 KiB
Raw Permalink Blame History

Scroll Jank Investigation & Fix (120Hz Android / Mali G715)

Overview

During M3/M4 development, profiling on physical 120 Hz hardware (Pixel 9 Pro, Mali G715, Android 17, 1280×2856, falsePrerotation=1) revealed periodic mid-scroll frame gaps (17–55 ms against the 8.33 ms budget). Stage-timestamp instrumentation (STG/IT/FR/VK/PRES/ SCN/OTHR/FLCK, all behind --features perf) isolated three distinct root causes. All three are fixed; the app is verified on the phone.

Final scorecard (warm, measured 4.5 s mid-screen swipe, 8 580 files grid):

metric baseline (M3) RENDER_AHEAD + full-cache fix (final)
frame cadence median 8.67 ms (judder) 8.34 ms 8.33 ms (exact 120 Hz)
cadence > 16.7 ms (2+ slots) ~6 % ~6 % 0.9 % (5/552)
worst gap in swipe 55 ms 292 ms¹ 28.3 ms
PRES phase median (vs vsync) 6 509 µs 1 992 µs ~994 µs
PRES > 8 330 µs (late) 100 % 0 % 0 %
slow Event::Other spikes — ~40 / 20 s 2 (launch only)

¹ single outlier = app background/foreground transition.


1. Root cause #1 — phase: present landed after the compositor deadline

Symptom: every rendered frame was shown one vsync late (effective ~60 Hz + judder) even though each render only took 4–8 ms.

Cause: the render was triggered by input events at an arbitrary phase inside the 8.33 ms slot; the present then landed past the compositor's ~5.5 ms deadline, so the frame could only be scanned out on the next slot.

Fix (two parts, both in the vendored backend/renderer):

  1. VSYNC_LOCKED_RENDER (vendor/i-slint-backend-android-activity-1.18.1/lib.rs): while animating (active animations or pointer active within 200 ms — Slint has no fling physics, so a direct drag sets no animation), input events only mark the window dirty; the render happens on the next vsync wake, giving a deterministic present phase.
  2. RENDER_AHEAD (vendor/i-slint-renderer-skia/wgpu_30_surface.rs): present the frame prepared by the previous render() at the start of the current one (phase = wake + ~1.1 ms), then prepare the next frame without presenting. One slot of constant latency; the present timing is fully decoupled from the render duration. Activated per frame (RENDER_AHEAD_ACTIVE): only locked (animating) renders use the hold-without-present pipeline; idle/model-update renders present immediately.

Crash fixed along the way — wgpu AlreadyAcquired: wgpu's Presentation tracks the acquired swapchain image independently of the Rust Arc. The legacy (unlocked) path used to drop a held frame without presenting it; the drop does not clear the Presentation, so the next get_current_texture panicked with "Surface image is already acquired" (killed the window at launch). Rule: a held frame must be PRESENTED, never merely dropped, before the next acquire. discard_pending_frame() (resize/reconfigure) therefore presents too — the compositor absorbs the one-frame size change.


2. Root cause #2 — Skia final flush (fixed earlier, M3)

Slint's default Skia renderer issued a synchronous GrDirectContext::flush(None) at the end of every frame; on Mali G715 that blocked the CPU 19–24 ms. Removed in vendored i-slint-renderer-skia/lib.rs (see docs/BUGS/slint-skia-final-flush-jank.md).


3. Root cause #3 — full-res prefetch churn: freeing 50 MB on the UI thread

Symptom: after #1 and #2, the gallery still showed ~40 CPU spikes of 9–43 ms per 20 s (≈7/s) — SLOWEV NonMain with cpu ≈ wall, i.e. pure CPU inside window.process_event(Wake), render=0. Sltest (no gallery code) does not show these, so the cause was app-side.

Localization: OTHR (timing of Event::Other closures drained in process_event — the invoke_from_event_loop queue) + INVK_TAG (push-site tags) showed 106 of 112 slow closures were the full-load-arrival closure (median 21 ms CPU), plus 9 set_status mislabeled by off-by-one (all fullload on re-correlation).

Mechanism (two compounding bugs in the M4.1 viewer prefetch):

  1. Churn loop. prefetch_full (drain tick) idly decodes full-res images for visible cells, cached in an 8-slot / 64 Mpx LRU (FullCache). The viewport holds ~20 cells ⇒ every insert evicts, and the evicted path is visible again ⇒ immediately re-prefetched. Steady state: decode → evict → re-decode forever — 137 full decodes in 20 s with the viewer closed.
  2. Eviction freed on the UI thread. Each evicted entry is a 50 MB-class Vec<u8>. FullCache::insert evicted (and thus free()d) the old blob synchronously on the UI thread: 20–52 ms of CPU per eviction (FLCK ins_us: median 21.4 ms when evicting, 4 µs when not — perfect correlation with the OTHR spikes).

Fix (src/lib.rs):

  1. Tombstone cooldown — full_evicted_recent (path → time). Idle prefetch skips paths evicted within EVICT_COOLDOWN (60 s); a tap (urgent) clears the tombstone and proceeds. Churn drops from 137 decodes/20 s to ~11 (initial cache fill only).
  2. Off-thread reaper — FullCache::insert now returns the evicted (path, rgba) pairs; the UI thread moves the blobs (a pointer swap) into REAPER_TX; a nice-style low-priority full-reaper thread drops them at 500 ms cadence. Insert cost: median 4 µs (was 21 ms).
  3. Tombstones cleared on list reset / world teardown with the other full-cache state.

Verification: FLCK ins_us median 4 µs / max 17 µs; OTHR slow closures 122 → 2 (launch set_list warm-up only); SLOWEV > 8 ms: 40 → 3 in 20 s; swipe cadence as in the scorecard.


4. Residual (accepted / open)

  • ~0.9 % two-slot gaps (16.8–17.7 ms) and a single 28.3 ms gap in a warm swipe. The 28.3 ms case is one 8.3 ms render with SKD = 4.5 ms (VK SKD max=57 ms over the run) — Mali GPU cache miss on freshly uploaded textures; renders otherwise 2–4 ms.
  • Mali G715 sits at 150–419 MHz during scroll (low duty cycle; no root to force the 940 MHz max). A faster clock would shrink SKD variance.
  • dumpsys gfxinfo is blind to Slint's NativeActivity window; Perfetto FrameTimeline cannot attribute app-side jank here — all numbers in this doc come from the app-side perf log.

5. Instrumentation reference (all --features perf)

line source meaning
IT backend event loop per-iteration: poll/first-ev/timers/ev/render/anim + LV/Flickable/input/timeout/wake counters
STG backend event loop iteration summary (wake, poll, events, lastrender)
FR window rendering notifier per rendered frame: cumulative ms, draw µs, gap ms
VSYNC vsync callback frame time + monotonic
PRES renderer surface presented frame idx, monotonic, present µs (phase vs VSYNC mon)
VK renderer (vkprobe) per-stage µs: ACQ/CLR/SKD/SKF/ORD/PRE
VKU src/gputex.rs thumb texture upload: create µs + write µs
SCN renderer (scn) scene op census per frame
SLOWEV backend event > 5 ms with wall vs CPU time
OTHR backend process_event slow invoke_from_event_loop closure (wall + CPU)
INVK / INVK_TAG backend / app push site of every cross-thread closure
FLCK app full-load closure full-cache insert: size, LRU before/after, insert µs