Greg Pomerantz
baff764b0d
sltest (minimal 100-row grid), phone, 2x4s drags, 1433 transitions: - steady 401-frame burst: phase 0.39-1.06ms (spread 0.67, was 1.5), 1/401 slot jumps, 0 doubles — the held frame presents at render start (edge+~1ms), constant phase, 4ms deadline margin - residual 0.7% drops/doubles concentrated at drag start/stop transitions - spike classifier (rcpu): all 13 spikes >6ms are CPU-bound (Skia/driver CPU, not GPU block) and render-ahead ABSORBS them (13 spikes -> 1 skipped frame) Remaining: user finger-perception test (sltest + gallery), then the 1.3% CPU spikes if anything remains.
118 lines
6.6 KiB
Markdown
118 lines
6.6 KiB
Markdown
# 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
|
||
|
||
### 2026-07-09 — sltest baseline + model correction (builds slt1-slt3)
|
||
|
||
- **H6 RULED OUT / FIXED**: sltest's blocking FileLogger replaced with a
|
||
non-blocking drain-thread logger. No crash, no behavior change beyond
|
||
log I/O coming off the render path.
|
||
- **MODEL CORRECTION (major)**: the "Choreographer callback arrives 2.5-6 ms
|
||
after the edge" belief from earlier sessions was WRONG — it came from the
|
||
STG `wake=` field, which actually measures the poll's block time (first
|
||
event), not callback latency. Measured from the VSYNC line itself
|
||
(ftn = vsync edge, mon = callback ran): **callback delivery = edge+0.52 ms
|
||
median, p90 0.65, max 1.8 ms** (sltest, phone). The callback fires ON the
|
||
edge.
|
||
- **H5 RULED OUT for the poll phase**: `pcpu` (CPU time inside
|
||
poll_events) = 2% of wall — the UI thread sleeps in epoll normally; it is
|
||
not spinning or descheduled while waiting. The wake→poll path is healthy:
|
||
poll start ≈ edge−2.3, byte at edge+0.5, return at edge+0.5, render 2.3-4.3
|
||
ms, present ≈ edge+3-4 ms — INSIDE the 5.5 ms deadline at the median.
|
||
(The early-waker's edge−0.8 wake is redundant with the on-edge
|
||
Choreographer wake — both are fine; the waker stays as fallback.)
|
||
- **Baseline zero-jank metrics (sltest, phone, 991 transitions)**:
|
||
DROPPED 0.71%, WASTED 0.91%, phase p10-p90 = 2.64-4.13 ms (1.5 ms
|
||
spread), 12.5% consecutive phase jumps >1 ms. Median behavior is correct;
|
||
the visible judder is the variance.
|
||
- **H2/H3 CONFIRMED (residual cause)**: per-frame render = 3.5 ms median
|
||
but spikes to 10.7 ms. Stage breakdown (sltest, phone): SKD (Skia draw)
|
||
1.07 ms median / 5.2 max; CLR (wgpu clear submit) 0.8 / 3.2; PRE 1.0 / 2.5;
|
||
SKF 0.3; ORD 0.35. Spikes push presents past the deadline (the drops) and
|
||
shake the phase (the judder). GPU submit overhead (2.45 ms median) exceeds
|
||
the actual scene draw (1.07 ms) — four wgpu submits per frame.
|
||
- **Next (implemented, phone-measurement pending)**: RENDER-AHEAD
|
||
re-enabled under the corrected model. With the wake on the edge, the held
|
||
frame is presented at the START of the render (edge+~1.5 ms, constant
|
||
phase, 4 ms margin) and a spike only stretches the PREPARE phase of the
|
||
frame held for the next slot — spikes stop delaying visible frames.
|
||
Behavior verified on the emulator (scroll, settle, mid-drag pause/resume,
|
||
no AlreadyAcquired, no black window). The phone is the only remaining
|
||
test: expect drops → ~0 and phase spread → <0.5 ms IF spikes were the
|
||
cause; `rcpu` (CPU time inside do_render) classifies any residual spikes
|
||
(CPU work vs GPU/driver block).
|
||
- **Emulator caveat**: the emulated Choreographer fires 9-10 ms late and the
|
||
SF pipeline is slow — the emulator cannot reproduce or validate 120 Hz
|
||
cadence; it is for behavior verification only. Phone remains the test
|
||
target.
|
||
|
||
### 2026-07-09 (2) — render-ahead on the phone (run slt4)
|
||
|
||
Render-ahead re-enabled (held frame presented at render START). sltest,
|
||
phone, 2×4 s drags, 1433 transitions:
|
||
- Steady burst (401 frames / 3.3 s): phase 0.39-1.06 ms (p10-p90,
|
||
spread 0.67 — was 1.5), slot jumps 1/401 (0.25%), doubles 0.
|
||
- Overall: DROPPED 0.70%, WASTED 0.70% — concentrated in the
|
||
17/62/87-frame bursts at drag START/STOP (locked↔unlocked transition +
|
||
fling decay), not in steady scroll.
|
||
- Render wall: med 3.68 ms, p90 3.67, p99 3.9 — tight.
|
||
- **Spike classifier (rcpu): all 13 spikes >6 ms are CPU-bound**
|
||
(rcpu≈wall, e.g. 17.5/15.2 ms) — Skia/driver CPU work, NOT
|
||
GPU/driver blocking. Render-ahead absorbs them: 13 spikes → 1 skipped
|
||
frame in the burst.
|
||
- Status: steady-state minimal-app scroll is effectively zero-jank by the
|
||
measured definition. Remaining work: (a) user finger-perception test on
|
||
sltest AND the gallery (textures, 8580 files), (b) if anything remains,
|
||
attack the 1.3% CPU spikes (Skia), (c) burst-boundary transitions
|
||
(drag start/stop) if visible.
|
||
- sltest logging bug noted: the non-blocking drain thread went silent
|
||
mid-idle (file frozen, process alive) — likely a /sdcard FUSE flush
|
||
stall on the per-line flush. Batch-flush (N lines or 100 ms) needed for
|
||
long runs.
|
||
|
||
### Remaining plan
|
||
1. User finger test: sltest first (minimal), then gallery with the
|
||
render-ahead build (already built, aarch64).
|
||
2. If residual jank on gallery: same sltslot.py analysis on the gallery
|
||
perf log; spikes there are textured (bigger SKD) — the absorption
|
||
should still hold; CPU-spike attack (Skia) as fallback.
|
||
3. Batch-flush fix for sltest's logger before longer phone sessions.
|