From e49d0e606fe679aee92e17de7ff4178e8477357f Mon Sep 17 00:00:00 2001 From: iris <2+iris@noreply.localhost> Date: Sat, 5 Sep 2026 20:07:20 -0400 Subject: [PATCH] RUST.md, DECISIONS.md, IRIS.md: iris's host-GPU frame time, 2026-09-05 Takes the -gpu host pair the earlier software-mode comparison flagged as missing. Under real GPU rendering (--features force-gles: the default Vulkan backend has no adapter at all under plain host-GPU boot, confirmed by the exact wgpu error), iris's median frame (15.0ms) is faster than Compose's (20.0ms) on the same session content -- the opposite shape from the software-mode table. The new redraw-to-submit/submit-to-present split shows iris's own CPU work is a median 0.2ms per frame; almost the whole frame is time handing off to the driver, consistent with (but not proof of) the software-mode gap being mostly SwiftShader's CPU rasterisation cost rather than iris-specific slowness. A same-mode software force-gles run, meant to isolate the backend, hit a third distinct crash instead (SwiftShader's GL path reports itself as OpenGL ES 3.0, which has no compute shaders, and iris's device request assumes them unconditionally) -- real scope to fix, not done here, so the software-mode question stays open. A real intermittent touch-scroll dropout was also reproduced (six consecutive swipes produced zero redraws while taps kept working; an identical retry then succeeded) and is not explained. The idle-redraw and virtualised-culling findings from the software-mode pass were confirmed to hold under real GPU rendering too. DECISIONS.md's DEFERRED item carries the updated table; the iris-vs- Masonry choice itself is still Iris's to make. IRIS.md records the FrameReport::record_split/FrameStats::cpu_p50/gpu_wait_p50 API from the prior commit (e2a1fad), which this pass's measurement used. Co-Authored-By: Claude Fable 5.1 --- docs/DECISIONS.md | 30 ++++++++ docs/IRIS.md | 23 ++++++ docs/RUST.md | 173 ++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 226 insertions(+) diff --git a/docs/DECISIONS.md b/docs/DECISIONS.md index 1d04d26..681be6d 100644 --- a/docs/DECISIONS.md +++ b/docs/DECISIONS.md @@ -104,3 +104,33 @@ marked **DEFERRED** are ones the agent chose not to decide alone. with the caveats above rather than as a single number — or ask for a same-profile, same-GPU-mode rerun first. RUST.md's I5 box has the full account. + + **Updated 2026-09-05, the `-gpu host` pair taken.** Real GPU rendering + (`force-gles` -- the default Vulkan backend has no adapter at all under + plain host-GPU boot, confirmed by the exact `wgpu` error) reverses the + software-mode shape: + + | app | build | GPU mode | frames | janky % | p50 | p90 | p99 | worst | cpu p50 | gpu-wait p50 | + |---|---|---|---|---|---|---|---|---|---|---| + | Compose (in-app report) | debug | host (virgl) | 1268 | 96.4% late | 20.0ms | 28.4ms | 37.7ms | -- | -- | -- | + | iris (`FrameReport`) | **release**, `force-gles` | host (virgl) | 62 | 41.94% | 15.0ms | 21.8ms | 37.1ms | 37.1ms | 0.2ms | 12.9ms | + + Under real GPU rendering iris's median frame is *faster* than + Compose's, not the 2-3x-slower shape the software-mode table shows. A + new split inside `FrameReport` (redraw-to-submit vs. submit-to-present, + commit `e2a1fad`) says why: iris's own CPU work per frame is a median + 0.2ms -- almost the entire frame is time spent handing the frame to the + driver, not in iris's layout/text/primitive code. This is consistent + with the earlier software-mode gap being mostly SwiftShader's CPU + rasterisation cost rather than an iris-specific slowness, but is not + proof of it: a same-mode software `force-gles` run to isolate the + backend crashed for an unrelated reason (SwiftShader's GL path reports + itself as OpenGL ES 3.0, which has no compute shaders, and iris's device + request assumes them unconditionally) — real scope to fix, not done + here — and the two apps' frame populations still differ in kind the same + way the software-mode caveats describe. A real intermittent touch- + scroll dropout was also reproduced this pass (six consecutive swipes + produced zero redraws while taps kept working; an identical retry then + succeeded) and is not explained. RUST.md's I5 box, "Where iris's frame + time goes, 2026-09-05, the `-gpu host` pass," has the full account. The + iris-vs-Masonry choice itself is still Iris's to make. diff --git a/docs/IRIS.md b/docs/IRIS.md index 70398ed..821a510 100644 --- a/docs/IRIS.md +++ b/docs/IRIS.md @@ -348,3 +348,26 @@ TEXTURES.md's "Recommended shape" and "Implemented, 2026-09-04". `wgpu::BindGroup` and draw call instead of a slot in the shared array — invisible from the widget API, visible only in `UiRenderNode`'s internals and in `iris`'s device requirements. + +## 2026-09-05: `FrameReport` splits each frame at `queue.submit` + +`FrameStats` gains two fields, and `FrameReport` gains a second recording +method, to answer "is a slow frame iris's own CPU work or the driver/GPU" +with a number instead of a guess (RUST.md's I5 box). + +- **`FrameReport::record_split(total, submit_to_present)`** is a second way + to record a frame, alongside the existing `record(total)` (unchanged, + and still what a caller with no split should use — it now reads as + `cpu_p50 == total`, `gpu_wait_p50 == 0`, rather than fabricating a + number for a half it never measured). +- **`FrameStats` gains `cpu_p50` and `gpu_wait_p50`**: medians of + redraw-start-to-submit and submit-to-after-`present()` respectively, + independent of each other and of the existing `p50`/`p90`/`p99`/`worst` + (which are unchanged, and still over the whole frame). The Android + renderer's `draw()` now returns the `submit_to_present` `Duration` it + measured, which `android::view::render()` passes to `record_split`. +- **Caveat carried in both doc comments**: `submit_to_present` is not + fenced against the GPU actually finishing — it is "how long the CPU was + blocked handing the frame to the driver," not a confirmed GPU-completion + time. Enough to separate "iris is slow building the frame" from "iris is + slow handing it off," not enough to claim an exact GPU budget. diff --git a/docs/RUST.md b/docs/RUST.md index ab4f192..225f921 100644 --- a/docs/RUST.md +++ b/docs/RUST.md @@ -58,6 +58,26 @@ session spending an afternoon on them again. still hers to make, not decided here. I5's own box, "Update, 2026-09-05, later the same day" has the full account. +- **The `-gpu host` pair this box's own DEFERRED item flagged as missing + is now taken, 2026-09-05, and it changes the picture.** Under real GPU + rendering (`--features force-gles`, since the default Vulkan backend has + no adapter under plain host-GPU boot -- confirmed by the exact crash + message), iris's median frame (15.0ms, `FrameReport`) is *faster* than + Compose's (20.0ms, in-app report) on the same session content, the + opposite shape from the software-mode table. The new CPU/GPU split + (`FrameReport::record_split`, `iris/core/src/render/frame_report.rs`, + commit `e2a1fad`) shows why: iris's own redraw-to-submit work is a + median 0.2ms; almost the whole frame is time handing off to the driver. + Software-mode `force-gles` crashes for a third, distinct reason + (SwiftShader's GL path reports itself as ES 3.0, which has no compute + shaders, and iris's device request assumes them unconditionally), so + this pass could not isolate SwiftShader-Vulkan as the sole cause of the + software-mode gap. A real intermittent touch-scroll dropout was also + reproduced and left unexplained (not the same as the earlier pass's + script-bug dropout). I5's box, "Where iris's frame time goes, + 2026-09-05, the `-gpu host` pass" has the full account, all four + findings, and what verification did and did not re-run. + `DECISIONS.md`'s DEFERRED item has the updated table. - **I5's Android integration is done and measured, 2026-09-05.** The transcript screen runs on-device against a real `ai-server`, with real scrolling, real touch-drag panning and tap-by-name accessibility all @@ -3012,6 +3032,159 @@ silently on real hardware. this table's headline numbers below rather than a decision made here. + **Where iris's frame time goes, 2026-09-05, the `-gpu host` pass this + box's own "not attempted" flagged.** New code first: `FrameReport` + (`iris/core/src/render/frame_report.rs`) now splits each sample at + `queue.submit` into `cpu_p50` (redraw-start to submit -- iris's own + layout/text/primitive-building work) and `gpu_wait_p50` (submit + through `present()` -- wherever a driver/compositor wait would show + up), and a new `force-gles` Cargo feature + (`iris/Cargo.toml`/`android-app/Cargo.toml`) switches the Android + `wgpu::Instance` from `Backends::PRIMARY` to `Backends::GL` at + compile time -- there is no way to hand an environment variable to an + already-launched Android process on this machine, so a runtime + switch was not an option. `app/iris-scroll.sh` extracts + `transcript-bench.sh`'s exact 24-swipe/6-cycle loop for iris's own + demo app. Commit `e2a1fad`. + + **Host GPU, default (Vulkan) backend -- crashes immediately, exactly + as the "Vulkan in the emulator" section already predicted.** Cold + boot (AVD snapshot cleared by hand -- `emu`'s wrapper has no flag for + this, matching the documented GPU-config-switch trap) under `emu + up`'s own default `GPU_HOST_FEATURES=-feature -Vulkan` (Vulkan + explicitly *off* under plain host-GPU boot, confirmed by reading + `emulator-tools/bin/emu` itself), release build, `transcript-screen`. + `dev.iris.android.demo` aborts on `surface_changed` before a single + frame: + + Abort message: 'Could not get adapter!: NotFound { active_backends: Backends(VULKAN), + requested_backends: Backends(VULKAN | METAL | DX12 | BROWSER_WEBGPU), + supported_backends: Backends(VULKAN | GL), no_fallback_backends: Backends(0x0), + no_adapter_backends: Backends(VULKAN), incompatible_surface_backends: Backends(0x0) } + + i.e. this boot mode offers a GL device only, and `wgpu`'s default + `Backends::PRIMARY` never tries it. Rebuilt and reinstalled with + `--features transcript-screen,force-gles`: no crash, real content on + screen (`wgpu_hal::gles::egl` picks up virgl/the real host GPU, same + harmless `D2`/`D2Array` heuristic warning I2 already found benign). + + **Host GPU, `force-gles` -- a real number, and it changes the + picture.** Same 24-swipe/6-cycle loop (`app/iris-scroll.sh`), same + sandbox session content class as the earlier pass (a fresh session, + `fda668c4d7e60dd9`, 30 identical sent messages -- heading/bold/ + italic/inline-code/link/list/fenced-code -- since the earlier pass's + sandbox data does not persist across a server rebuild and had been + wiped by the time this pass started). Compose (debug) via + `transcript-bench.sh -s benchsession2` on the same session, same + emulator boot: + + | app | build | GPU mode | frames | janky % | p50 | p90 | p99 | worst | cpu p50 | gpu-wait p50 | + |---|---|---|---|---|---|---|---|---|---|---| + | Compose (in-app report) | debug | host (virgl) | 1268 | 96.4% late | 20.0ms | 28.4ms | 37.7ms | -- | -- | -- | + | iris (`FrameReport`) | **release**, `force-gles` | host (virgl) | 62 | 41.94% | 15.0ms | 21.8ms | 37.1ms | 37.1ms | 0.2ms | 12.9ms | + + **Under real GPU rendering, iris's median frame is faster than + Compose's, not 2-3x slower** -- the opposite shape from the + software-mode table above. And the CPU/GPU split says why: iris's + own redraw-to-submit work is a median 0.2ms, essentially free: almost + the entire 15.0ms median frame is `gpu_wait_p50` (submit through + `present()`), i.e. time spent on the driver/compositor side, not in + iris's layout or primitive-building code. That is consistent with + the software-mode number being dominated by SwiftShader's CPU + rasterisation cost rather than by anything iris itself does slowly -- + the leading candidate the software-mode box above named but could + not confirm directly. It is **not proof**: `gpu_wait_p50` is "how + long the CPU was blocked handing the frame to the driver," per + `FrameReport::record_split`'s own doc, not a fenced GPU-completion + time, and the two apps' frame populations still differ in kind the + same way the software-mode table's caveats describe (Compose + free-runs its own Choreographer-driven count over 36.8s including + settle time; iris's 62 are real redraws only, matching this box's + "does not redraw while idle" finding below) -- so "15.0ms vs. 20.0ms" + should be read as "the same order of magnitude, on real GPU + hardware," not as a precise ranking. + + **A real, reproduced instance of the previously-suspected + intermittent touch-scroll dropout**, distinct from the earlier + pass's script-bug explanation for its own dropout. After a fresh + `am start`, six consecutive swipes (`ui-trace record --do "swipe ..."`, + matching `iris-scroll.sh`'s own gesture exactly) produced **zero** + `render():` log lines and a screenshot confirming the list had not + moved, while a `tap 'Message'` immediately before and after each + block of swipes reliably produced `render()` calls -- so touch + delivery and the render loop were both alive throughout; only the + drag-to-pan gesture failed to register. A later, otherwise-identical + retry (same coordinates, same session, same app process still + running) succeeded and produced 120 `render()` calls with `active` + climbing smoothly 63->113 across the gesture (see below). Not + root-caused this pass -- `iris::sense::DragArbiter` (`iris/src/ + sense.rs`) requires a `dy`/`dx` past `DRAG_SLOP` on an early frame of + the gesture to leave `Undecided`, so a dropped or coalesced initial + `ACTION_MOVE` under emulator input-injection load is the leading + candidate, but this pass did not instrument that path to confirm it. + Practical effect on the table above: the 62-frame iris run was the + one attempt this pass that worked on the first try, so it stands as + the number, but a next pass should budget for retries rather than + treating a single `iris-scroll.sh` invocation as reliable. + + **Redundant-work check (no optimising, as instructed), host GPU, + `force-gles`.** (1) **Idle redraw: zero**, confirmed fresh this pass + -- `adb logcat -c` then a 5s settled wait with nothing on screen + touched produced no `render():` lines, matching the software-mode + pass's earlier finding on the same code path. (2) **A scrolling + frame does not relayout the whole list**: during the successful + 120-call run, `active=` climbed 63, 68, 73, 78, 83, 88, 93, 98, 103, + 108, 113 -- one small step per frame-or-two, not a jump to the full + 148-widget count (`widgets=148` in the same log lines), consistent + with I3's virtualised culling doing its job under real GPU rendering + the same way the software-mode pass found under SwiftShader. Neither + check isolates further than the software-mode pass already did; both + are restated here because this pass had a live device to check them + against a different backend, and they held. + + **Software mode (`EMU_GPU=software`), `force-gles` -- crashes for a + third, different reason, so this pass could not isolate + SwiftShader-Vulkan as the sole cause of the software-mode gap.** Cold + boot under `EMU_GPU=software`, same release build with `--features + transcript-screen,force-gles`. `wgpu_hal::gles::adapter` finds a real + adapter (`Renderer: Android Emulator OpenGL ES Translator (Google + SwiftShader)`, `Version: OpenGL ES 3.0`), further than the plain + host-GPU/default-backend attempt got -- but `AndroidRenderer::new`'s + device request then aborts: + + Abort message: 'Could not get device!: RequestDeviceError { inner: Core(LimitsExceeded( + FailedLimit { name: "max_compute_workgroups_per_dimension", requested: 65535, allowed: 0 } )) }' + + i.e. iris's device descriptor asks for compute-shader limits + unconditionally, and SwiftShader's software GL path reports itself + as OpenGL ES 3.0 -- compute shaders are an ES 3.1+ feature, so the + allowed limit is 0. This is a different failure from both the host- + GPU/default-backend crash above (no adapter at all) and the earlier + Venus/gfxstream failure "Vulkan in the emulator" documents (a + different Vulkan implementation's external-memory gap) -- three + distinct emulator/backend incompatibilities found across this + project's Android work, not one recurring bug. **Not fixed this + pass**: making iris's device request tolerant of a downlevel GL + adapter (requesting compute limits only when the adapter actually + reports them) is real scope, not a measurement task. Consequence for + the software-mode question this step was meant to answer: it remains + open whether SwiftShader-Vulkan specifically (rather than GLES in + general) explains the ~80-150ms software-mode numbers, since no GLES + number under software mode could be taken at all. + + **Verification, this update.** `cargo fmt --all` (no diff), + `cargo clippy --workspace --all-targets` (no warnings from the new + code; pre-existing `wgpu`/`winit`/`naga` future-incompat notices + only) both re-run and clean this pass. `cargo test --workspace` and + `cargo ndk ... test`/`clippy` for `iris-android-app` were **not** + re-run this pass -- the previous pass on this identical diff had + already run and reported them clean, and this pass's host was + disk-pressure-limited (93% full, a concurrent `ai-server` rebuild in + progress) when the repeat attempt was made, so it was stopped rather + than left to spend 50+ minutes doing no useful work; see commit + `e2a1fad`'s own message. `docs/DECISIONS.md`'s DEFERRED item is + updated with this section's host-GPU table below. + ## For the next agent What to do when you pick this up, in order, so nothing here has to be