client: Linux keystroke latency trails alacritty and foot #403

Closed

opened 2026-09-25 01:34:55 +09:00 by natsukium · 1 comment

natsukium commented

2026-09-25 01:34:55 +09:00

Owner

Keystroke-to-pixel latency on Linux with wl-latency (docs/reference/benchmarks.md, felis 9d1d842f, ms):

	felis	alacritty	foot
mean	5.3	4.6	3.2
95th percentile	6.4	5.4	3.9

felis's key goes client → daemon → PTY → echo → daemon → client → present, two more hops than a single-process terminal.

Candidates:

crates/felis-render-wgpu/src/lib.rs configures desired_maximum_frame_latency: 2 with PresentMode::AutoVsync; measure 1.
Whether the daemon sends the echoed update to the client as soon as it has parsed it, or waits for a paint tick.
Whether the client waits for a redraw request cycle after the update arrives.

Done when each hop is timed and the ones that wait are removed or shown to be needed.

Keystroke-to-pixel latency on Linux with `wl-latency` (`docs/reference/benchmarks.md`, felis `9d1d842f`, ms): | | felis | alacritty | foot | |---|---|---|---| | mean | 5.3 | 4.6 | 3.2 | | 95th percentile | 6.4 | 5.4 | 3.9 | felis's key goes client → daemon → PTY → echo → daemon → client → present, two more hops than a single-process terminal. Candidates: - `crates/felis-render-wgpu/src/lib.rs` configures `desired_maximum_frame_latency: 2` with `PresentMode::AutoVsync`; measure 1. - Whether the daemon sends the echoed update to the client as soon as it has parsed it, or waits for a paint tick. - Whether the client waits for a redraw request cycle after the update arrives. Done when each hop is timed and the ones that wait are removed or shown to be needed.

natsukium referenced this issue

2026-09-25 01:35:05 +09:00

bench: follow up the 9d1d842f cross-terminal run #405

natsukium commented

2026-09-25 02:57:09 +09:00

Author

Owner

Linux measurement (kilimanjaro, niri 60 Hz, NVIDIA through the pinned ICD described in #398). felis main ef96bb46 release build. Load average (1 min) is given with each figure.

Each hop, timed with `strace -f -ttt` on both processes

Both processes ran under strace -f -ttt -e trace=read,write,recvmsg,sendmsg,recvfrom,sendto. The session was a wrapper that sets a bar cursor and then exec cat > /dev/null, as the latency suite does, so the echo comes from the line discipline. wtype a typed 10 keys 300 ms apart into the focused window (188x93, load about 4). Medians over the 10 keys, with strace's per-syscall overhead included, so absolute values are high by a few tens of µs per hop:

hop	evidence	median	max
key event read from Wayland → input sent to the daemon	client `recvmsg(wl)` → tokio `sendto(sock, 20 B)`	0.100 ms	0.386
socket	→ daemon `recvfrom(20 B)`	0.060 ms	0.112
daemon input → PTY write	→ `write(master, 1 B)`	0.097 ms	0.527
PTY write → echo read	→ reader `read(master) = 1`	0.037 ms	2.236
echo read → update sent	parser marks dirty (eventfd) → tokio `sendto(sock, 247 B)`	0.233 ms	0.836
socket	→ client `recvfrom(247 B)`	0.031 ms	0.123
update received → buffer committed to the compositor	→ last `sendmsg(wl)` (attach/commit)	1.386 ms	6.435
key event → commit		1.906 ms	7.287

Answers to the candidates:

The daemon does not wait for a paint tick. The echoed update leaves 0.2 ms after the echo is read, woken through the parser's eventfd.
The client does not wait out a redraw-request cycle either. The main loop wakes about 0.1 ms after the update arrives, and the first Wayland request goes out 0.15 ms after it.
Nearly all of felis's own time is in the client's frame build. A second trace that includes ioctl/poll/futex shows, for one key: 0.57 ms of main-thread CPU with no syscalls, then the GPU submit ioctl, a 0.12 ms poll on the render fence, then the commit.

What the 0.57 ms is: the whole grid is rebuilt and re-uploaded per keystroke

The client under perf record -e cycles:u --call-graph lbr while typing 200 keys 50 ms apart (188x93 grid), main thread, inclusive:

Renderer::render 69%, of which:
- Renderer::build_cell_instances (crates/felis-render-wgpu/src/lib.rs:1091) 27%: CellPainter::extend_instances (crates/felis-render-wgpu/src/instances.rs:403) 14.8% self, resolve_cell_colors (instances.rs:480) 7.4%, ScreenBuffer::cell 6.6%.
- Renderer::upload_frame_buffers (lib.rs:1339) → Queue::write_buffer 19.7%, almost all of it memmove (17%): the full instance buffer is copied every frame.
- populate_glyphs 6%, queue.submit 6%, CommandEncoder::finish 5%.

One changed cell costs a full-grid instance rebuild plus a full-buffer upload, so the cost scales with window area, not with the change.

`desired_maximum_frame_latency: 1` (local patch, not committed)

wl-latency through the harness (crossterm.py run latency --terminals foot, 200 samples, 150 ms delay), alternating builds:

build	load (start → end)	felis mean / p50 / p95	foot mean / p95 (same run)
latency 2 (main)	15.1 → 6.8	5.52 / 5.30 / 6.99 ms	2.38 / 3.07
latency 1	6.8 → 6.3	6.63 / 6.29 / 9.55 ms	2.37 / 3.12
latency 2 (main)	6.3 → 4.1	5.35 / 5.21 / 6.77 ms	2.29 / 2.94
latency 1	4.1 → 3.1	5.41 / 5.21 / 6.92 ms	2.28 / 2.74

No gain, and the commit is already issued right after the render fence, so a second frame in flight is not what the key waits on. Keep 2.

Where the rest of the gap is

felis's own path, key → commit, is about 1.9 ms even with strace overhead included. The instrument reads 5.2-5.5 ms, so about 3.4 ms falls after the commit: the compositor latching and compositing felis's GPU buffer, plus screencopy. foot's whole path is 2.3 ms with an shm buffer. The published alacritty figure (4.6 ms), also a GPU buffer, suggests most of that post-commit time is shared by GPU-buffer clients on this compositor and driver, not specific to felis. I did not instrument niri, so this attribution is by elimination.

Proposed fix, with expected gain

Rebuild instances only for damaged rows and upload only the changed ranges (queue.write_buffer at an offset), instead of build_cell_instances plus a full upload_frame_buffers per frame. Expected: most of the 0.5-0.6 ms frame build per keystroke at 188x93, less at the harness's 106x35, and less CPU per frame under floods (#398/#397).
Daemon and IPC hops (about 0.5 ms with strace, less without): no waits to remove. The two extra socket hops cost about 0.1 ms together.
desired_maximum_frame_latency stays at 2 (measured, no gain from 1).

Linux measurement (kilimanjaro, niri 60 Hz, NVIDIA through the pinned ICD described in #398). felis `main` ef96bb46 release build. Load average (1 min) is given with each figure. ## Each hop, timed with `strace -f -ttt` on both processes Both processes ran under `strace -f -ttt -e trace=read,write,recvmsg,sendmsg,recvfrom,sendto`. The session was a wrapper that sets a bar cursor and then `exec cat > /dev/null`, as the latency suite does, so the echo comes from the line discipline. `wtype a` typed 10 keys 300 ms apart into the focused window (188x93, load about 4). Medians over the 10 keys, with strace's per-syscall overhead included, so absolute values are high by a few tens of µs per hop: | hop | evidence | median | max | |---|---|---|---| | key event read from Wayland → input sent to the daemon | client `recvmsg(wl)` → tokio `sendto(sock, 20 B)` | 0.100 ms | 0.386 | | socket | → daemon `recvfrom(20 B)` | 0.060 ms | 0.112 | | daemon input → PTY write | → `write(master, 1 B)` | 0.097 ms | 0.527 | | PTY write → echo read | → reader `read(master) = 1` | 0.037 ms | 2.236 | | echo read → update sent | parser marks dirty (eventfd) → tokio `sendto(sock, 247 B)` | 0.233 ms | 0.836 | | socket | → client `recvfrom(247 B)` | 0.031 ms | 0.123 | | update received → buffer committed to the compositor | → last `sendmsg(wl)` (attach/commit) | **1.386 ms** | 6.435 | | **key event → commit** | | **1.906 ms** | 7.287 | Answers to the candidates: - The daemon does not wait for a paint tick. The echoed update leaves 0.2 ms after the echo is read, woken through the parser's eventfd. - The client does not wait out a redraw-request cycle either. The main loop wakes about 0.1 ms after the update arrives, and the first Wayland request goes out 0.15 ms after it. - Nearly all of felis's own time is in the client's frame build. A second trace that includes `ioctl`/`poll`/`futex` shows, for one key: 0.57 ms of main-thread CPU with no syscalls, then the GPU submit `ioctl`, a 0.12 ms `poll` on the render fence, then the commit. ## What the 0.57 ms is: the whole grid is rebuilt and re-uploaded per keystroke The client under `perf record -e cycles:u --call-graph lbr` while typing 200 keys 50 ms apart (188x93 grid), main thread, inclusive: - `Renderer::render` 69%, of which: - `Renderer::build_cell_instances` (`crates/felis-render-wgpu/src/lib.rs:1091`) 27%: `CellPainter::extend_instances` (`crates/felis-render-wgpu/src/instances.rs:403`) 14.8% self, `resolve_cell_colors` (`instances.rs:480`) 7.4%, `ScreenBuffer::cell` 6.6%. - `Renderer::upload_frame_buffers` (`lib.rs:1339`) → `Queue::write_buffer` 19.7%, almost all of it `memmove` (17%): the full instance buffer is copied every frame. - `populate_glyphs` 6%, `queue.submit` 6%, `CommandEncoder::finish` 5%. One changed cell costs a full-grid instance rebuild plus a full-buffer upload, so the cost scales with window area, not with the change. ## `desired_maximum_frame_latency: 1` (local patch, not committed) `wl-latency` through the harness (`crossterm.py run latency --terminals foot`, 200 samples, 150 ms delay), alternating builds: | build | load (start → end) | felis mean / p50 / p95 | foot mean / p95 (same run) | |---|---|---|---| | latency 2 (main) | 15.1 → 6.8 | 5.52 / 5.30 / 6.99 ms | 2.38 / 3.07 | | latency 1 | 6.8 → 6.3 | 6.63 / 6.29 / 9.55 ms | 2.37 / 3.12 | | latency 2 (main) | 6.3 → 4.1 | 5.35 / 5.21 / 6.77 ms | 2.29 / 2.94 | | latency 1 | 4.1 → 3.1 | 5.41 / 5.21 / 6.92 ms | 2.28 / 2.74 | No gain, and the commit is already issued right after the render fence, so a second frame in flight is not what the key waits on. Keep 2. ## Where the rest of the gap is felis's own path, key → commit, is about 1.9 ms even with strace overhead included. The instrument reads 5.2-5.5 ms, so about 3.4 ms falls after the commit: the compositor latching and compositing felis's GPU buffer, plus screencopy. foot's whole path is 2.3 ms with an shm buffer. The published alacritty figure (4.6 ms), also a GPU buffer, suggests most of that post-commit time is shared by GPU-buffer clients on this compositor and driver, not specific to felis. I did not instrument niri, so this attribution is by elimination. ## Proposed fix, with expected gain 1. Rebuild instances only for damaged rows and upload only the changed ranges (`queue.write_buffer` at an offset), instead of `build_cell_instances` plus a full `upload_frame_buffers` per frame. Expected: most of the 0.5-0.6 ms frame build per keystroke at 188x93, less at the harness's 106x35, and less CPU per frame under floods (#398/#397). 2. Daemon and IPC hops (about 0.5 ms with strace, less without): no waits to remove. The two extra socket hops cost about 0.1 ms together. 3. `desired_maximum_frame_latency` stays at 2 (measured, no gain from 1).

natsukium referenced this issue

2026-09-25 07:49:43 +09:00

render: glyph populate walk and scroll still cost the whole grid per frame #422

natsukium referenced this issue from a pull request that will close it,

2026-09-25 08:38:28 +09:00

render: repaint and upload only the rows a frame changed #424

natsukium closed this issue

2026-09-25 10:31:46 +09:00

Commenting is not possible because the repository is archived.