iris/ai-app
1
0 Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

iris: redrawing one widget cost O(its own primitives squared)

Browse Source 
Iris's report was that expanding a tool card holding a long,
horizontally-scrolling edit lags on her phone. The cause is not text
layout: shaping and rasterising a 51,200-glyph block is 20ms, and the
frame that drew it took 1.37 seconds.

A widget redrawn in place frees every primitive it owned and writes
fresh ones. Freeing compacts each layer's draw order with swap_remove,
so ~N primitives are renumbered, and finding the handle to renumber was
a linear scan of everything that widget drew -- O(N^2) in the widget's
own primitive count. A paragraph never notices; one text widget holding
a whole old_string and new_string is every glyph in the card.

The arena now records, per slot, where that slot's handle sits in its
owner's ActiveData::primitives, written at the one place a handle is
taken (Painter::own), and apply_free indexes straight to it.

    50,000 glyphs, redrawn:  before 636ms   after 2.4ms
    per glyph:               before 12.7us  after 0.043us, flat in N

benches/message_list.rs gains scenario (g) for it, reporting per-glyph
because flat is the pass condition and a total hides it. That file had
also stopped running entirely: scenarios (a) and (e) built a LazySpan
with no mask around it, which the span now asserts against, so the
benchmark panicked on its second line. Fixed here too.

Also, on Iris's instruction: the copied report no longer inlines a tail
of the app log. Dev Updater's Runtime tab reads the same ring through
devlog's provider, so it was the same lines twice; the diagnostics pane
still names the provider's authority to read them from.
This commit is contained in:
iris committed 2026-09-08 22:22:06 -04:00
1 parent 4fdabc39d0
commit 1318e149f5
8 files changed
+241 -97
Download Patch File Download Diff File Expand all files Collapse all files

No files matched your search

client-core/src/log_ring.rs
+12 -73
View File
@@ -9,14 +9,18 @@
//! of whichever platform logger was already installed (`android_logger`,
//! `env_logger`) rather than instead of it -- see [`RingLogger`].
//!
//! Two consumers, both reading the same ring rather than each keeping
//! their own: the bench app's `Copy report`/`Diagnostics` (which reads
//! [`LogRing::tail_text`] and [`LogRing::summary`]) and whatever hands the
//! log out of the process -- on Android, the `DevLogProvider` Dev Updater
//! queries, which reads [`LogRing::since`] and [`LogRing::newest_seq`].
//! That is why reading does not consume: a line already handed over must
//! still be in the report, and a report taken twice must say the same
//! thing.
//! Three consumers, all reading the same ring rather than each keeping
//! their own: whatever hands the log out of the process -- on Android, the
//! `DevLogProvider` Dev Updater queries, which reads [`LogRing::since`]
//! and [`LogRing::newest_seq`] -- the bench app's diagnostics pane, which
//! only counts it ([`LogRing::summary`]), and the panic hook
//! ([`LogRing::try_tail_text`]). That is why reading does not consume: a
//! line already handed over must still be readable, and a report taken
//! twice must say the same thing.
//!
//! Nothing inlines the log into a copied report any more (2026-09-08):
//! Dev Updater reads it directly, so a second copy on the clipboard was
//! the same lines twice.
use std::collections::VecDeque;
use std::sync::{Arc, Mutex, OnceLock};
@@ -32,15 +36,6 @@ use std::time::{SystemTime, UNIX_EPOCH};
pub const DEFAULT_MAX_LINES: usize = 2000;
pub const DEFAULT_MAX_BYTES: usize = 256 * 1024;
/// How many of the ring's newest lines [`LogRing::tail_text`] includes.
/// Sized for a phone's share sheet rather than for the ring itself: 150
/// lines of `HH:MM:SS.mmm LEVEL target: message` is a few KiB, comfortably
/// short of whatever made pasting the full (up to 2000-line) ring into a
/// chat's message box laggy on Iris's phone. The full ring is still
/// reachable through `devlog`'s provider, so this only bounds what a
/// report inlines.
pub const COPY_REPORT_TAIL_LINES: usize = 150;
/// One recorded line. `seq` is assigned by the ring and only ever
/// increases, so a reader that remembers where it got to can ask for what
/// came after -- and a gap in the sequence is exactly the lines the bound
@@ -249,35 +244,6 @@ impl LogRing {
.join("\n")
}
/// The newest `max_lines` lines, formatted, with a first line naming
/// how many older ones were left out of *this* text when the ring held
/// more than that -- what `Copy report` appends instead of
/// [`Self::to_text`].
///
/// Iris's own report: pasting the full ring (over a thousand lines on
/// a session that ran with tracing on) into a phone's message box was
/// what "causes a lot of lag" meant (docs/IRIS_TODO.md, 2026-09-07
/// night) -- nothing is actually lost, since `devlog`'s provider still
/// hands Dev Updater's Runtime tab the whole ring; this only caps what
/// gets inlined into a share.
pub fn tail_text(&self, max_lines: usize) -> String {
let lines = self.snapshot();
if lines.len() <= max_lines {
return lines
.iter()
.map(LogLine::format)
.collect::<Vec<_>>()
.join("\n");
}
let omitted = lines.len() - max_lines;
let tail = lines[lines.len() - max_lines..]
.iter()
.map(LogLine::format)
.collect::<Vec<_>>()
.join("\n");
format!("{omitted} earlier lines omitted; full log in Dev Updater's Runtime tab\n{tail}")
}
/// The newest `max_lines` lines, formatted, or `None` if the ring is
/// locked at this instant.
///
@@ -591,33 +557,6 @@ mod tests {
assert_eq!(ring.to_text().lines().count(), 2);
}
#[test]
fn tail_text_is_the_whole_ring_untouched_when_under_the_cap() {
let ring = LogRing::new(100, 1 << 20);
fill(&ring, 5);
assert_eq!(ring.tail_text(150), ring.to_text());
}
#[test]
fn tail_text_trims_to_the_newest_lines_and_says_how_many_were_left_out() {
let ring = LogRing::new(1000, 1 << 20);
fill(&ring, 200);
let tail = ring.tail_text(150);
let mut lines = tail.lines();
assert_eq!(
lines.next().unwrap(),
"50 earlier lines omitted; full log in Dev Updater's Runtime tab"
);
let rest: Vec<&str> = lines.collect();
assert_eq!(rest.len(), 150, "exactly the cap, after the header line");
assert!(
rest[0].ends_with("line 50"),
"the oldest line kept is the 50th, not line 0: {}",
rest[0]
);
assert!(rest.last().unwrap().ends_with("line 199"));
}
#[test]
fn try_tail_text_gives_the_newest_lines_with_no_header() {
let ring = LogRing::new(1000, 1 << 20);
docs/IRIS.md
+44 -1
View File
@@ -12,7 +12,50 @@ things still stay out.
An entry gives the date, what changed, why, and a short before/after where
it helps judge the change without the session that made it. Newest first.
## 2026-09-08 (newest): one `ScrollController`, a `Scrollable` trait, and `Pin`
## 2026-09-08 (newest): redrawing one widget cost O(its own primitives squared)
Your report -- expanding a tool card with a long horizontally-scrolling
edit in it lags -- is a framework defect, not a text-layout one, and the
size of it is not close: **a 51,200-glyph block took 1.37 seconds to
redraw, of which shaping and rasterising the text was 20ms.** It is 29ms
now, and the cost is linear in the glyph count rather than quadratic.
What happened. A widget redrawn in place frees every primitive it owned
and writes fresh ones. Freeing compacts each layer's draw order with
`swap_remove`, and every primitive that gets swapped into a hole has to be
told its new position -- so a widget with N primitives generates ~N
renumberings. Finding the handle to renumber was a **linear scan of
everything that widget drew**, which made the pass N^2. For a paragraph
that is nothing. For one text widget holding a whole `old_string` and
`new_string`, N is every glyph in the card.
The fix is a back-pointer: the primitive arena now records, per slot,
where that slot's handle sits in its owner's `ActiveData::primitives`
(`Primitives::handle_index`), written at the one place a handle is taken
(`Painter::own`). `apply_free` indexes straight to it.
50,000 glyphs, redrawn: before 636ms/redraw after 2.4ms/redraw
per glyph: before 12.7us after 0.043us (flat in N)
`benches/message_list.rs` grew scenario **(g)** for it, and the number to
read is per-glyph: flat as N grows is the pass condition, and a total
hides it. Two things about that file: it also caught the quadratic in
`--phone`-sized text, and it had stopped running at all -- scenarios (a)
and (e) built a `LazySpan` with no mask around it, which the span now
asserts against, so the whole benchmark panicked on its second line.
Fixed in the same change.
**What this does not fix, and what I would do next.** An open card still
shapes, rasterises and submits *every* glyph of its input and output, not
the screenful you can see -- iris does not cull within a widget, and a
tool card is the one place that bites, because an `Edit`'s `old_string`
and `new_string` go onto the card whole. The output half is already capped
(`OUTPUT_LINES`/`OUTPUT_BYTES` in `tool.rs`, 80 lines or 4 KiB behind a
"Show all"); the *input* half has no cap at all, and that is the
asymmetry to close. Wrapping the block, which you asked for, changes the
shape but not this cost: the same glyphs are laid out either way.
## 2026-09-08: one `ScrollController`, a `Scrollable` trait, and `Pin`
Your three points on `docs/SCROLL.md`, in one change. The shape is the one
you proposed: **a controller both scrolling widgets contain**, rather than
docs/IRIS_TODO.md
+15
View File
@@ -944,6 +944,21 @@ diagnosis and what building it actually costs.
the shaped-mask work (`.masked_by`, 38bf630) is the likeliest, since the
old chain was `.masked()` *inside* the padding. Left ticked with the
original symptom recorded rather than deleted, in case it comes back.
- [ ] **An open tool card lays out every glyph of its input, however
long.** iris does not cull within a widget -- a `Text` shapes,
rasterises and submits the whole string whether or not the box it sits
in can show it -- and a tool card is where that bites, because an
`Edit`'s `old_string` and `new_string` go onto the card whole. The
*output* half is already capped at 80 lines or 4 KiB behind a "Show
all" (`tool.rs`'s `OUTPUT_LINES`/`OUTPUT_BYTES`); the input half has no
cap at all, which is the asymmetry to close, and the cheaper fix of the
two. Culling inside a `Text` is the other, and is a real design
question: the shaped layout knows where each glyph is, so a viewport
test is possible, but nothing else in iris cares where the screen is.
Found 2026-09-08 chasing Iris's "expanding the edit card lags" report,
whose actual cause was the quadratic `apply_free` (fixed; docs/IRIS.md).
Wrapping the block does not change this cost -- the same glyphs are laid
out either way.
- [ ] **No overflow ellipsis.** `TextAttrs` can wrap or not wrap; there is
no "one line, ellipsised" the way `maxLines = 1` + `TextOverflow.
Ellipsis` gives Compose. A tool card's summary is clipped instead, so
iris/android-app/src/bench_client.rs
+7 -12
View File
@@ -699,6 +699,13 @@ impl BenchClient {
/// it copies the diagnostics pane's own text instead, with a first
/// line saying so -- `diagnostics_text` needs no prior button press
/// either, so this is never actually empty-handed.
/// The report carries **no copy of the app log** (removed 2026-09-08,
/// Iris: "please remove the app log from the diagnostics. Those can be
/// obtained through dev updater now"). Dev Updater's Runtime tab reads
/// the same ring through `devlog`'s provider, and the diagnostics
/// pane's own `devlog provider:` line names the authority to read it
/// from -- so what is left here is the measurement, not a second copy
/// of something already reachable.
fn copy_report(&mut self, rsc: &mut Rsc) {
let Some(platform) = &self.platform else {
log::info!("iris bench report: no platform handle, can't reach the clipboard");
@@ -711,18 +718,6 @@ impl BenchClient {
self.diagnostics_text(rsc)
),
};
// The ring's tail goes on the clipboard, not the full ring, and
// not into the on-screen pane either: the full ring can be over a
// thousand lines with tracing on, and pasting that into a phone's
// message box was Iris's own "causes a lot of lag" report. The
// full ring is still reachable through Dev Updater's Runtime tab
// (`devlog`'s provider reads the same ring) -- this only bounds
// what gets inlined here.
let report = format!(
"{report}\n\n=== app log ({}) ===\n{}",
crate::app_log::ring().summary(),
crate::app_log::ring().tail_text(client_core::log_ring::COPY_REPORT_TAIL_LINES)
);
if platform.copy_to_clipboard("iris bench report", &report) {
log::info!("iris bench report: copied to clipboard");
} else {
iris/benches/message_list.rs
+84 -2
View File
@@ -49,6 +49,13 @@
//! only the rows on the far side of it, never redraw the ones already
//! correctly placed.
//!
//! - (g) redraw-one-big-text: a single text widget of N glyphs redrawn in
//! place, which is what a tool card rebuilt on a tap costs. Every one of
//! its primitives is freed and rewritten, and so renumbered in the
//! layer's draw order -- the pass that used to be O(N^2) there
//! (`UiRenderState::apply_free`, fixed 2026-09-08). The number to watch
//! is per-glyph: it must stay flat as N grows, not grow with it.
//!
//! (f), many images with zero steady-state bind-group creation, needs a
//! real `wgpu` device and lives in `iris/examples/bench_images.rs` instead,
//! driven through `run-headless.sh` -- see that file's header.
@@ -120,10 +127,19 @@ fn build_message_list(
list.push_back(LazyItem::new(i as u64, row));
}
let list = rsc.ui.widgets.add_strong(list);
let weak = list.weak();
// Masked because a `LazySpan` requires it -- it draws a row straddling
// an edge in full and relies on the clip to cut it off, and asserts as
// much rather than letting the overhang reach the screen. The app's
// own transcript screen puts the same mask around the same widget.
let root = rsc.ui.widgets.add_strong(Masked {
shape: None,
inner: list.any(),
});
// Driven through the span's own `ScrollController`, like every other
// scroll area in iris: what this measures has to be the path the app
// actually takes.
(list.weak(), list.any())
(weak, root.any())
}
fn report(label: &str, elapsed: std::time::Duration, draws: u64, rewrites: u64, moves: u64) {
@@ -360,7 +376,15 @@ fn bench_expand_holds_edge(n: usize, growths: usize) {
}
let list = rsc.ui.widgets.add_strong(list);
let list_weak = list.weak();
let root = list.any();
// Masked for `build_message_list`'s reason -- a `LazySpan` requires it.
let root = rsc
.ui
.widgets
.add_strong(Masked {
shape: None,
inner: list.any(),
})
.any();
let growable = growable.unwrap();
let mut render = UiRenderState::new();
@@ -408,6 +432,61 @@ fn bench_expand_holds_edge(n: usize, growths: usize) {
);
}
/// (g) One text widget of `chars` characters, redrawn in place `redraws`
/// times -- an open tool card whose content is rebuilt, or any widget
/// holding a lot of text that a tap changes.
///
/// A redraw frees every primitive the widget owned and writes fresh ones,
/// so every glyph is renumbered in its layer's draw order. Finding the
/// handle to renumber used to be a scan of everything the same widget
/// drew, which made one redraw quadratic in its own glyph count: 1.37s for
/// 51,200 glyphs on this machine, against 20ms to shape and rasterise the
/// same text. Print per-glyph rather than per-redraw, since flat is the
/// pass condition and a total says nothing without dividing it.
fn bench_redraw_big_text(chars: usize, redraws: usize) {
let mut rsc = BenchRsc {
ui: UiData::default(),
};
// One character per glyph, and varied so nothing can collapse the
// string into a repeat.
let content: String = (0..chars)
.map(|i| char::from(b'a' + (i % 26) as u8))
.collect();
let mut text = Text::new(content);
text.wrap = true;
let text = rsc.ui.widgets.add_strong(text);
let handle = text.weak();
let root = text.any();
let mut render = UiRenderState::new();
render.resize((1080.0, 2000.0));
render.update(&root, &mut rsc);
render.take_counters();
let mut total = std::time::Duration::ZERO;
for _ in 0..redraws {
// Asking for the widget mutably is what marks it for redraw --
// the same path a caller changing its content takes.
rsc.ui.widgets.get_mut(&handle).unwrap();
let start = Instant::now();
render.update(&root, &mut rsc);
total += start.elapsed();
}
let (draws, rewrites, moves, _shapes) = render.take_counters();
report(
&format!("(g) redraw one {chars}-glyph text, {redraws}x (totals)"),
total,
draws,
rewrites,
moves,
);
println!(
" per redraw: {:.3}ms, per glyph: {:.4}us",
total.as_secs_f64() * 1000.0 / redraws as f64,
total.as_secs_f64() * 1_000_000.0 / (redraws * chars) as f64,
);
}
fn main() {
println!("iris message-list benchmark -- release build, this machine's CPU");
for &n in &[100usize, 1_000, 10_000] {
@@ -425,4 +504,7 @@ fn main() {
for &n in &[100usize, 1_000, 10_000] {
bench_expand_holds_edge(n, 40);
}
for &chars in &[1_000usize, 10_000, 50_000] {
bench_redraw_big_text(chars, 10);
}
}
iris/core/src/render/primitive.rs
+40
View File
@@ -124,6 +124,20 @@ macro_rules! primitives {
pub struct Primitives {
instances: Vec<PrimitiveInstance>,
assoc: Vec<WidgetId>,
/// Where each slot's [`PrimitiveHandle`] sits in its owner's
/// `ActiveData::primitives` -- the index that makes
/// `UiRenderState::apply_free` O(1) per renumbered primitive instead
/// of a scan of everything the owner drew. Written by
/// [`Self::set_handle_index`] from the one place a handle is taken
/// into that vec (`Painter::own`), and dead alongside its `assoc`
/// entry, which is what keeps the two in step.
///
/// Without it a text widget that is freed and redrawn in one frame
/// costs O(glyphs^2): every one of its glyphs is renumbered, and each
/// renumbering scanned all of them. Measured 2026-09-08 at 1.37s for a
/// 51,200-glyph block on this machine, against 20ms for the shaping
/// and rasterising of the same text.
handle_idx: Vec<u32>,
/// Slots freed since the last [`Self::apply_free`]. Deliberately not
/// reusable yet: the layer that drew one still names it in its draw
/// order until that call compacts the order, so handing it out again
@@ -145,6 +159,7 @@ impl Default for Primitives {
Self {
instances: Default::default(),
assoc: Default::default(),
handle_idx: Default::default(),
freed: Vec::new(),
reusable: Vec::new(),
data: Default::default(),
@@ -154,6 +169,11 @@ impl Default for Primitives {
}
impl Primitives {
/// A slot whose handle has not been recorded yet -- see
/// [`Self::handle_idx`]. No owner draws four billion primitives, so
/// the sentinel cannot collide with a real index.
const NO_HANDLE: u32 = u32::MAX;
/// Writes a primitive into the arena and hands back its slot and its
/// entry in the per-primitive data. The caller (`UiRenderState`) puts
/// the slot into a layer's draw order -- an instance that no layer
@@ -212,10 +232,12 @@ impl Primitives {
let slot = if let Some(i) = self.reusable.pop() {
self.instances[i] = inst;
self.assoc[i] = id;
self.handle_idx[i] = Self::NO_HANDLE;
i
} else {
self.instances.push(inst);
self.assoc.push(id);
self.handle_idx.push(Self::NO_HANDLE);
self.instances.len() - 1
};
slot as u32
@@ -248,10 +270,28 @@ impl Primitives {
self.assoc[slot as usize]
}
/// Records that `slot`'s handle is `idx` entries into its owner's
/// `ActiveData::primitives`. Called once per primitive, by the one
/// place that puts a handle into that vec.
pub fn set_handle_index(&mut self, slot: u32, idx: u32) {
self.handle_idx[slot as usize] = idx;
}
/// Where `slot`'s handle sits in its owner's `ActiveData::primitives`
/// -- see [`Self::handle_idx`]. `None` only for a slot whose owner
/// never took the handle, which nothing in this crate does.
pub fn handle_index(&self, slot: u32) -> Option<usize> {
match self.handle_idx[slot as usize] {
Self::NO_HANDLE => None,
idx => Some(idx as usize),
}
}
pub fn clear(&mut self) {
self.updated = true;
self.instances.clear();
self.assoc.clear();
self.handle_idx.clear();
self.freed.clear();
self.reusable.clear();
self.data.clear();
iris/core/src/ui/painter.rs
+17 -2
View File
@@ -56,10 +56,25 @@ impl<'a> Painter<'a> {
self.rsc.ui_mut().masks.push_ref(self.mask);
}
let slot = h.slot;
self.primitives.push(h);
self.own(h);
slot
}
/// Take ownership of a handle this widget just wrote.
///
/// The one place a `PrimitiveHandle` enters `self.primitives`, and so
/// the one place that can keep `Primitives::handle_index` in step with
/// where it lands -- which is what `UiRenderState::apply_free` reads
/// instead of scanning this vec. Anything that writes a primitive
/// without coming through here leaves that index unset, and its
/// position in a layer's draw order stops being renumbered.
fn own(&mut self, h: PrimitiveHandle) {
self.state
.primitives
.set_handle_index(h.slot, self.primitives.len() as u32);
self.primitives.push(h);
}
/// Writes a primitive to be rendered
pub fn primitive<P: Primitive>(&mut self, primitive: P) {
self.primitive_at(primitive, self.region)
@@ -276,7 +291,7 @@ impl<'a> Painter<'a> {
if self.mask != MaskIdx::NONE {
self.rsc.ui_mut().masks.push_ref(self.mask);
}
self.primitives.push(h);
self.own(h);
}
pub fn render_text(
iris/core/src/ui/render_state.rs
+22 -7
View File
@@ -207,14 +207,29 @@ impl UiRenderState {
fn apply_free(&mut self) {
for (layer, order) in self.layers.iter_mut() {
for change in order.apply_free() {
// Straight to the handle, never a scan of everything the
// owner drew: a widget freed and redrawn in one frame has
// *every* one of its primitives renumbered here, so a scan
// makes this pass quadratic in that widget's primitive
// count -- 1.37s for one 51,200-glyph text block, against
// 20ms to shape and rasterise the same text (measured
// 2026-09-08). `Primitives::handle_index` is written where
// the handle is taken, in `Painter::own`.
let owner = self.primitives.owner(change.slot);
if let Some(active) = self.active.get_mut(&owner) {
for h in &mut active.primitives {
if h.layer == layer && h.slot == change.slot {
h.pos = change.pos;
break;
}
}
let Some(idx) = self.primitives.handle_index(change.slot) else {
continue;
};
if let Some(active) = self.active.get_mut(&owner)
&& let Some(h) = active.primitives.get_mut(idx)
{
debug_assert!(
h.layer == layer && h.slot == change.slot,
"slot {} says it is handle {idx} of {owner:?}, which is slot {} in layer {}",
change.slot,
h.slot,
h.layer,
);
h.pos = change.pos;
}
}
}