Greg Pomerantz
d5bbb41bbd
Residual scroll jank at 120 Hz (suspected Slint event-loop bug) needs per-frame + per-stage timing the logcat ring buffer can't hold. New cargo feature `perf` (default OFF — all sites are cfg-gated, zero overhead when off): - FR: per-frame app-side render cost + frame gap, from the rendering notifier (BeforeRendering/AfterRendering). - STG: event-loop stage costs (wake/timers/events/poll/lastrender) from timestamps instrumented into the pinned vendor copy of i-slint-backend-android-activity (stg.rs; Cargo.toml now depends on it directly + optional under `perf`). - DECODE: per-thumbnail-job cost on the workers. - All lines mirrored to /sdcard/Download/.gallery_perf.log (logcat rotates too fast at ~120 lines/s). Format + reading guide: docs/BUGS/scroll-jank-120hz.md.
57 lines
2.9 KiB
Markdown
57 lines
2.9 KiB
Markdown
# Residual scroll jank at 120 Hz — `perf` instrumentation
|
|
|
|
Status (2026-10-29): the two *known* jank sources are fixed
|
|
(GPU-resident thumbnails, §8.7 of HANDOFF.md; thread priorities). A small
|
|
amount of residual jank remains on the phone (Mali G715) — suspected Slint
|
|
event-loop bug, not yet proven. This doc describes the instrumentation used
|
|
to hunt it.
|
|
|
|
## The `perf` cargo feature (off by default)
|
|
|
|
`cargo apk2 build --release --features perf --target x86_64-linux-android`
|
|
|
|
With `perf` off every instrumentation site is behind `#[cfg(feature = "perf")]`
|
|
— the code is eliminated, zero runtime overhead. With `perf` on, three
|
|
families of lines are logged (tag `gallery`) and mirrored to
|
|
`/sdcard/Download/.gallery_perf.log` (the logcat ring buffer rotates too fast
|
|
to be useful at ~120 lines/s). Only lines starting with `FR `, `STG `,
|
|
`DECODE ` or `gallery: [W` are mirrored; logcat gets everything as before.
|
|
|
|
## Line formats
|
|
|
|
- `FR <t_ms> d=<µs> gap=<ms>` — once per presented frame, from the
|
|
rendering notifier on the UI thread. `t` = ms since process start
|
|
(monotonic), `d` = app-side render cost (BeforeRendering→AfterRendering,
|
|
i.e. everything Slint does in its render pass), `gap` = ms since the
|
|
previous frame (120 Hz → 8.33 ms; a hitch = gap >> 8.33).
|
|
- `STG wake=<µs> timers=<µs> events=<µs> n=<events> poll=<µs> lastrender=<µs>`
|
|
— cost of the event-loop *stages* of the iteration just completed, from
|
|
timestamps instrumented into the vendored `i-slint-backend-android-activity`
|
|
(`vendor/i-slint-backend-android-activity-1.18.1/stg.rs`, `stg::snapshot()`):
|
|
`wake` = time from the previous iteration's poll-end to the first
|
|
Choreographer event (waker/wakeup latency), `timers` =
|
|
`update_timers_and_animations`, `events` = `process_event`, `n` = number of
|
|
polled events, `poll` = whole `poll_events`, `lastrender` = whole
|
|
`do_render` of the previous frame (draw + wgpu surface tail).
|
|
- `DECODE <ms> <hit|miss> <path>` — per-thumbnail-job cost on the worker
|
|
threads; correlates decode bursts against FR gap spikes.
|
|
|
|
## How to read a capture
|
|
|
|
1. `adb pull /sdcard/Download/.gallery_perf.log`.
|
|
2. Find hitched frames: `gap > ~20 ms` on `FR` lines.
|
|
3. For each hitch look at the same-frame `STG` line:
|
|
- big `wake` → the Choreographer waker was starved/delayed (the fixed
|
|
nice-+10 bug had exactly this signature);
|
|
- big `lastrender` → the previous frame's render tail (wgpu submit /
|
|
surface present) ran long;
|
|
- big `timers`/`events` → Slint-side event processing (our tick is
|
|
budgeted; a spike here that correlates with `DECODE` bursts is
|
|
cross-thread pressure).
|
|
4. If none of the stages explains the gap, the delay is *inside* wgpu/Vulkan
|
|
or in Slint's surface handling (the suspected-bug class).
|
|
|
|
The `STG` timestamps come from the pinned vendor crate; re-apply
|
|
`vendor/i-slint-backend-android-activity-1.18.1` (including `stg.rs`) when
|
|
bumping Slint.
|