irisandClaude Opus 5
c2ceaf01d6
"It still flickers sometimes" is not something a fix can be tested against,
so the first change is a counter. Drawing is the one place that knows both
what is on screen and what was built, so it asks: `covered()` compares the
rows in the viewport against the window and records how far short it fell
and which way. That turned a symptom into a number, and the number found
four separate causes -- three of which I would not have guessed, and one of
which I had already "fixed" twice.
- Opening a session recomputed the window before the scroll container had
measured anything. `maxValue` is zero then, which reads as the reader
being at the oldest end, so the window landed a whole transcript away
from where the session was about to open.
- A page of history recomputed it from a scroll position one layout out
of date -- stale by exactly the height of the page that had just
arrived. The reader's position is now carried across the change as a
row rather than as a pixel, and resolved through the row that *holds*
that seq, because a regroup can fold the row it named into another.
- The window was widened to cover the screen only when it was recomputed,
which was every two screens of movement. A fling covers a screen in a
frame or two, so it outran the window and arrived at rows that were
still spacers. Standing rows up a few per frame made that worse rather
than causing it: after a seed the built window is two screens wide and
grows two rows a frame. What is near the screen is now widened every
frame; only the outer bound is lazy.
- Both were measured in pixels, and a pixel budget cannot know how many
rows it covers until the rows have been measured -- which is never, on
the frame a session opens. The margins are now a number of screens *or*
a number of rows, whichever is larger.
The recompute moved to the transcript's placement, which is the one moment
both halves are current: the rows have just been measured and so has the
scroll container. Everywhere else it ran could be right about one and stale
about the other. It writes only when the answer changes, so a frame where
nothing moved costs one scan and no recomposition.
Two supporting fixes. `covered()` also repairs, so however the window goes
stale the damage is one frame rather than until the next scroll. And the
scroll position is now keyed per session -- `rememberScrollState()` is not
keyed, so a second session opened without leaving the screen inherited the
first one's offset and, worse for the window, its `maxValue`.
Verified on the emulator: flings up and down, three scroll-and-restore
cycles on a 92-row session and three reopens of a short one -- zero, where
before each reopen cost one to three. Placement stayed at 0.8ms.
Also here: crashes are recorded and travel out through the debug button, so
"it crashes opening that chat" arrives with a stack next time; the report
goes to the log as well as the clipboard, so a session driving the app over
adb can read it; and `trace-draw.sh` captures a labelled frame breakdown,
with a note that it must be run against the phone -- on this emulator two
thirds of a frame is `dequeueBuffer` and Compose's own draw is 0.40ms.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
130 lines
5.5 KiB
Bash
Executable File
130 lines
5.5 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# What a scrolling frame is actually spending its time in, by name.
|
|
#
|
|
# The app's own counters can time the code we wrote, and they showed that almost none of the frame
|
|
# is that code -- roughly a fortieth of the draw phase. The rest is inside the framework, which
|
|
# already brackets its own work with trace sections (measure, layout, draw, the position-callback
|
|
# dispatch, the per-node rect bookkeeping, semantics). This turns those on, drives a fling, and adds
|
|
# up what each section cost, so "the other eighty percent" gets a name instead of a hypothesis.
|
|
#
|
|
# atrace's text output rather than perfetto's protobuf on purpose: this needs no trace_processor
|
|
# build, and the question here is which sections dominate, which the text format answers directly.
|
|
#
|
|
# The absolute milliseconds from an emulator are worthless -- it renders in software, and its stock
|
|
# apps miss frames as badly as ours do. The *ranking* is what transfers, which is what this prints.
|
|
set -euo pipefail
|
|
|
|
app=com.example.aiapp
|
|
secs=6
|
|
swipes=12
|
|
out=/tmp/ai-app-trace.txt
|
|
top=25
|
|
# Empty means whatever `adb` picks by itself, which in this checkout is its own emulator. A phone
|
|
# needs naming, and a phone is the only place these numbers mean anything -- see the note at the
|
|
# foot of this file.
|
|
serial=()
|
|
|
|
while [ $# -gt 0 ]; do
|
|
case "$1" in
|
|
-t) secs=$2; shift 2 ;;
|
|
-n) swipes=$2; shift 2 ;;
|
|
-o) out=$2; shift 2 ;;
|
|
--top) top=$2; shift 2 ;;
|
|
-s) serial=(-s "$2"); shift 2 ;;
|
|
-h|--help)
|
|
echo "usage: $0 [-s serial] [-t seconds] [-n swipes] [-o file] [--top n]"
|
|
exit 0 ;;
|
|
*) echo "$0: unknown argument $1" >&2; exit 2 ;;
|
|
esac
|
|
done
|
|
|
|
if ! adb "${serial[@]}" shell pidof "$app" >/dev/null 2>&1; then
|
|
echo "$0: $app is not running -- open a session in it first" >&2
|
|
exit 1
|
|
fi
|
|
pid=$(adb "${serial[@]}" shell pidof "$app" | tr -d '\r')
|
|
|
|
# `view` carries Compose's measure/layout/draw and the View system's own; `gfx` carries the render
|
|
# thread and the frame boundaries. Buffer sized for a few seconds of a busy main thread: a fling
|
|
# emits a great many sections and a full buffer silently drops the end of the trace.
|
|
#
|
|
# A blocking capture with the gestures alongside it, rather than atrace's own --async_start /
|
|
# --async_dump pair: measured on this emulator, the asynchronous form returns a buffer of
|
|
# `entries-in-buffer: 0/0` however long it runs, and an empty trace reads exactly like an app that
|
|
# emitted no sections. Blocking, the same categories fill it immediately.
|
|
#
|
|
# `-a` is the flag the whole thing turns on. Without it atrace records only what the system emits,
|
|
# and every section Compose writes -- measure, layout, recomposition -- comes from `android.os.Trace`
|
|
# inside the app process, which stays switched off. The result looks like a successful capture and
|
|
# answers the question with the framework's half of the frame, which is not the half being asked
|
|
# about.
|
|
adb "${serial[@]}" shell atrace -a "$app" -b 65536 -t "$secs" -c view gfx input 2>/dev/null | tr -d '\r' >"$out" &
|
|
capture=$!
|
|
|
|
for _ in $(seq "$swipes"); do
|
|
adb "${serial[@]}" shell input swipe 540 1800 540 700 80 >/dev/null 2>&1
|
|
done
|
|
wait "$capture"
|
|
|
|
if ! grep -q tracing_mark_write "$out"; then
|
|
echo "$0: the trace holds no sections; another capture may hold the ftrace buffer" >&2
|
|
exit 1
|
|
fi
|
|
|
|
python3 - "$out" "$pid" "$top" <<'PY'
|
|
import collections, re, sys
|
|
|
|
path, pid, top = sys.argv[1], sys.argv[2], int(sys.argv[3])
|
|
# ftrace text: "<task>-<tid> (<pid>) [cpu] flags <ts>: tracing_mark_write: B|<pid>|<name>"
|
|
mark = re.compile(r"^\s*\S+-(\d+)\s+\(\s*(\d+|-+)\)[^:]*?\s+(\d+\.\d+):\s+tracing_mark_write:\s+(.*)$")
|
|
stacks = collections.defaultdict(list)
|
|
total = collections.Counter()
|
|
count = collections.Counter()
|
|
worst = collections.Counter()
|
|
frames = 0
|
|
|
|
for line in open(path, errors="replace"):
|
|
m = mark.match(line)
|
|
if not m:
|
|
continue
|
|
tid, owner, ts, body = m.group(1), m.group(2), float(m.group(3)), m.group(4)
|
|
parts = body.split("|")
|
|
if parts[0] == "B" and len(parts) >= 3:
|
|
if parts[1] != pid:
|
|
continue
|
|
stacks[tid].append((parts[2], ts))
|
|
elif parts[0] == "E":
|
|
if not stacks[tid]:
|
|
continue
|
|
name, began = stacks[tid].pop()
|
|
ms = (ts - began) * 1000.0
|
|
total[name] += ms
|
|
count[name] += 1
|
|
worst[name] = max(worst[name], ms)
|
|
if name.startswith("Choreographer#doFrame"):
|
|
frames += 1
|
|
|
|
if not total:
|
|
print("no sections for pid " + pid + " -- was the app in the foreground?")
|
|
raise SystemExit(1)
|
|
|
|
print(f"{frames} frames traced, {sum(count.values())} sections")
|
|
print()
|
|
print(f"{'section':<44}{'calls':>7}{'total ms':>10}{'mean':>8}{'worst':>8}")
|
|
for name, ms in total.most_common(top):
|
|
n = count[name]
|
|
label = name if len(name) <= 43 else name[:40] + "..."
|
|
print(f"{label:<44}{n:>7}{ms:>10.1f}{ms/n:>8.2f}{worst[name]:>8.1f}")
|
|
left = len(total) - top
|
|
if left > 0:
|
|
print(f"... {left} more sections not shown (--top to raise the limit)")
|
|
PY
|
|
|
|
# A note on where to run this.
|
|
#
|
|
# Not here. Measured on this checkout's emulator, a scrolling frame is 15ms of `Drawing` of which
|
|
# 10ms is `dequeueBuffer` and `postAndWait` -- the main thread blocked on the buffer queue, because
|
|
# the emulator renders in software -- while Compose's own `AndroidOwner:draw` is 0.40ms. The
|
|
# ranking that comes out is the ranking of the emulator's graphics stack, and it says nothing about
|
|
# a phone whose whole draw phase is 3.6ms. Point it at the device the numbers came from.
|