daemon: CPU time under sustained output is 1.3-1.9x the leading peer's #399

Closed

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

natsukium commented 2026-09-25 01:34:54 +09:00

Owner

Copy link

Under sustained output felis spends more CPU than its peers (docs/reference/benchmarks.md, felis 9d1d842f):

Workload	felis	best peer
vtebench, macOS	177 s	alacritty 108 s
DOOM-fire, macOS	33.9 s	alacritty 17.9 s
vtebench, Linux	132 s	alacritty 104 s
DOOM-fire, Linux	31.7 s	kitty 20.9 s

On macOS felis used about 1.65 cores for the length of the pass against alacritty's 0.9-1.0, and the published split puts 95% or more of it in the daemon (#398 questions that split; settle it first). #397 addresses the client's per-cell hashing and does not touch the daemon.

Throughput is not the problem: felis leads DOOM-fire's frame rate on both platforms. The cost is CPU spent per byte parsed.

Plan:

1. Profile the daemon under DOOM-fire and vtebench with samply (perf-trace skill). #394 has to land first, or the samply harness cannot find the systemd-run hand-off daemon.
2. Suspects to confirm or rule out: wakeups from the flood-drain yield and parse-lock hand-off added in #380; per-paint encoding of the client update; copies between the PTY reader thread and the parser.
3. Compare CPU time per MB before and after on the same workloads, with the load average recorded (the host is also the CI runner).

Done when the daemon's CPU per workload drops by a measured amount without losing frame rate or cat time, or the profile shows the remaining cost is inherent and the reason is recorded.

Under sustained output felis spends more CPU than its peers (`docs/reference/benchmarks.md`, felis `9d1d842f`): | Workload | felis | best peer | |---|---|---| | vtebench, macOS | 177 s | alacritty 108 s | | DOOM-fire, macOS | 33.9 s | alacritty 17.9 s | | vtebench, Linux | 132 s | alacritty 104 s | | DOOM-fire, Linux | 31.7 s | kitty 20.9 s | On macOS felis used about 1.65 cores for the length of the pass against alacritty's 0.9-1.0, and the published split puts 95% or more of it in the daemon (#398 questions that split; settle it first). #397 addresses the client's per-cell hashing and does not touch the daemon. Throughput is not the problem: felis leads DOOM-fire's frame rate on both platforms. The cost is CPU spent per byte parsed. Plan: 1. Profile the daemon under DOOM-fire and vtebench with samply (`perf-trace` skill). #394 has to land first, or the samply harness cannot find the systemd-run hand-off daemon. 2. Suspects to confirm or rule out: wakeups from the flood-drain yield and parse-lock hand-off added in #380; per-paint encoding of the client update; copies between the PTY reader thread and the parser. 3. Compare CPU time per MB before and after on the same workloads, with the load average recorded (the host is also the CI runner). Done when the daemon's CPU per workload drops by a measured amount without losing frame rate or `cat` time, or the profile shows the remaining cost is inherent and the reason is recorded.

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:32:44 +09:00

Author

Owner

Copy link

Linux profile of the daemon (kilimanjaro, i5-12400F, niri 60 Hz). felis main ef96bb46, release build with line tables. Load average (1 min) is given with each figure. The host was running CI the whole time (load 5-21), so treat single-run wall-clock figures as noisy; per-thread CPU splits and profile shares are stable across runs.

Method. samply cannot run here: perf_event_paranoid is 2 and there is no sudo. I used perf 7.2.7 in user-only mode (-e cycles:u --call-graph lbr), with the daemon started under perf (perf record … -- felis-daemon serve --socket $SOCK) and the client pointed at that socket. That is the same launch shape as the fixed samply-profile.sh (#394). Kernel time is not sampled at this paranoid level, so per-thread user/sys split, read syscall counts (/proc/<pid>/task/<tid>/io syscr/rchar) and voluntary context switches come from /proc read at the pass's start and end markers.

Where the daemon's CPU goes, per thread

workload	load	grid	felis-pty-parser	felis-pty-reader (user + sys)	tokio-rt-worker
DOOM-fire 15 s, manual	5.2	188x93	14.13 s	5.75 s (1.94 + 3.81)	0.41 s
DOOM-fire 20 s, harness	4.4-6.2	188x82	16.59 s	6.87 s	0.48 s
vtebench, all rows, harness	2.6-4.9	106x35	51.79 s	71.54 s	0.52 s
vtebench scrolling 12 s, manual	6.2	188x93	3.54 s	4.93 s (0.50 + 4.43)	0.22 s

The reader thread, which only calls read(2) and appends to the swap buffer, costs more than the parser on vtebench and about 28% of the daemon on DOOM-fire.

DOOM-fire parser profile (self time, % of parser samples)

Grid::put_grapheme (crates/felis-grid/src/editing.rs:209) 11.0, Params::push_run (crates/felis-vt/src/lib.rs:319) 10.7, Grid::print_wide_str (crates/felis-grid/src/sink.rs:896) 9.7, build_sink closure with Parser::advance inlined (crates/felis-daemon/src/parse_sink.rs:122) 8.9, StyleTable::intern (crates/felis-grid/src/style_table.rs:71) 8.2, Grid::csi_dispatch (crates/felis-grid/src/sink.rs:240) 7.4, Parser::advance_byte (crates/felis-vt/src/machine.rs:75) 6.0, unicode_width::lookup_width 6.1, Attributes::apply_sgr 4.2, hash_one<Attributes> 4.0, Attributes::equivalent 3.7, from_utf8 3.3.

Inclusive: print_utf8_run 36%, dispatch_csi 33%, and resync_pen_style (crates/felis-grid/src/lib.rs:1706, the StyleTable::intern hash lookup on every SGR) 21%.

vtebench scrolling parser: Grid::print_str 60% self, of which crates/felis-grid/src/sink.rs:136 alone is 24%. That line is the wide-partner check, which loads the target cell of a row that scrolling has just recycled, and costs a cache miss per line. scroll_full_screen_into_history 11%, scroll_region_up 6%.

The suspects, ranked

1. The reader's spin (MasterReader::read, crates/felis-pty/src/unix.rs:67-104, READ_SPIN_WINDOW 50 µs). On EAGAIN it retries non-blocking read(2) for 50 µs before poll(2). That window was measured against the macOS 1 KiB lockstep (3cc9cba0). On Linux, the same DOOM-fire pass with the spin set to 0 (env-gated local patch, not committed):

   spin	load	fps	reader user	reader sys	reads
   50 µs	21.1 / 17.6 / 13.0	648 / 936 / 954	1.43 / 2.03 / 1.73 s	2.25 / 3.04 / 3.18 s	1.04 / 1.56 / 1.47 M
   0	20.5 / 14.0 / 10.5	901 / 918 / 962	0.31 / 0.27 / 0.37 s	3.29 / 3.31 / 3.47 s	1.19 / 1.16 / 1.25 M

   The frame rate is unchanged within noise, and reader user time drops by 1.4-1.7 s per 12 s, about 7% of the daemon.

2. Tiny reads on line-heavy output. On scrolling the reader does 13-16 bytes per read(2), about 1.2 M reads/s, with 8-9.7 s of sys time per 12 s. The spin makes no difference there: the data is always present in 13-byte pieces. A local patch that sleeps 20 µs after a read under 256-2048 bytes while the parser is busy cut the reader from about 9.9 s to 0.76 s per 12 s (-92%), with scrolling medians 78-99 ms against 89-109 ms. The same back-off applied unconditionally starves the parser under DOOM-fire (933 → 400 fps; 4 KiB is the ceiling of one PTY read on Linux, N_TTY_BUF_SIZE), so a real fix must back off only while the parser still has a backlog. Details in #400.

3. SGR style interning, 21% of the parser under DOOM-fire. Every SGR re-interns the whole Attributes through the hash map (hash plus equality). A one-entry cache for the last (Attributes, StyleId), or skipping the intern when the SGR left the pen unchanged, removes most of that for streams that repeat colors. Expected gain: up to about 15-20% of parser time on DOOM-fire.

4. CSI parameter parsing (Params::push_run), 10.7% of the parser: the next parser-side candidate after interning.

5. Ruled out: the #380 flood-drain yield and parse-lock hand-off. All tokio workers together spend 0.41 s per 15 s of DOOM-fire (2% of the daemon), and the parser thread made about 190 voluntary context switches per second (2,858 in 15 s), so the hand-off is not a wakeup storm.

6. Ruled out: per-paint client-update encoding. wire::encode_row plus put_attr_run are 0.46% of all samples.

7. Ruled out: reader→parser copies. memmove is 0.26% of samples. The copy into the swap buffer is negligible next to the syscall cost.

Expected combined gain on Linux: removing most of the reader cost (items 1-2) takes about 25-55% off daemon CPU depending on the workload (5.75 of 20.3 s on DOOM-fire, 71.5 of 124 s on vtebench), which would put felis's vtebench total (132 s published) under alacritty's 104 s. Item 3 is a further 10-15% of daemon CPU on DOOM-fire. Before landing either, re-measure on a quiet host, and on macOS, where the spin was a measured win.

Linux profile of the daemon (kilimanjaro, i5-12400F, niri 60 Hz). felis `main` ef96bb46, release build with line tables. Load average (1 min) is given with each figure. The host was running CI the whole time (load 5-21), so treat single-run wall-clock figures as noisy; per-thread CPU splits and profile shares are stable across runs. **Method.** samply cannot run here: `perf_event_paranoid` is 2 and there is no sudo. I used `perf` 7.2.7 in user-only mode (`-e cycles:u --call-graph lbr`), with the daemon started under perf (`perf record … -- felis-daemon serve --socket $SOCK`) and the client pointed at that socket. That is the same launch shape as the fixed `samply-profile.sh` (#394). Kernel time is not sampled at this paranoid level, so per-thread user/sys split, `read` syscall counts (`/proc/<pid>/task/<tid>/io` `syscr`/`rchar`) and voluntary context switches come from `/proc` read at the pass's start and end markers. ## Where the daemon's CPU goes, per thread | workload | load | grid | `felis-pty-parser` | `felis-pty-reader` (user + sys) | `tokio-rt-worker` | |---|---|---|---|---|---| | DOOM-fire 15 s, manual | 5.2 | 188x93 | 14.13 s | 5.75 s (1.94 + 3.81) | 0.41 s | | DOOM-fire 20 s, harness | 4.4-6.2 | 188x82 | 16.59 s | 6.87 s | 0.48 s | | vtebench, all rows, harness | 2.6-4.9 | 106x35 | 51.79 s | **71.54 s** | 0.52 s | | vtebench `scrolling` 12 s, manual | 6.2 | 188x93 | 3.54 s | 4.93 s (0.50 + 4.43) | 0.22 s | The reader thread, which only calls `read(2)` and appends to the swap buffer, costs more than the parser on vtebench and about 28% of the daemon on DOOM-fire. ## DOOM-fire parser profile (self time, % of parser samples) `Grid::put_grapheme` (`crates/felis-grid/src/editing.rs:209`) 11.0, `Params::push_run` (`crates/felis-vt/src/lib.rs:319`) 10.7, `Grid::print_wide_str` (`crates/felis-grid/src/sink.rs:896`) 9.7, `build_sink` closure with `Parser::advance` inlined (`crates/felis-daemon/src/parse_sink.rs:122`) 8.9, `StyleTable::intern` (`crates/felis-grid/src/style_table.rs:71`) 8.2, `Grid::csi_dispatch` (`crates/felis-grid/src/sink.rs:240`) 7.4, `Parser::advance_byte` (`crates/felis-vt/src/machine.rs:75`) 6.0, `unicode_width::lookup_width` 6.1, `Attributes::apply_sgr` 4.2, `hash_one<Attributes>` 4.0, `Attributes::equivalent` 3.7, `from_utf8` 3.3. Inclusive: `print_utf8_run` 36%, `dispatch_csi` 33%, and `resync_pen_style` (`crates/felis-grid/src/lib.rs:1706`, the `StyleTable::intern` hash lookup on every SGR) **21%**. vtebench `scrolling` parser: `Grid::print_str` 60% self, of which `crates/felis-grid/src/sink.rs:136` alone is 24%. That line is the wide-partner check, which loads the target cell of a row that scrolling has just recycled, and costs a cache miss per line. `scroll_full_screen_into_history` 11%, `scroll_region_up` 6%. ## The suspects, ranked 1. **The reader's spin (`MasterReader::read`, `crates/felis-pty/src/unix.rs:67-104`, `READ_SPIN_WINDOW` 50 µs).** On `EAGAIN` it retries non-blocking `read(2)` for 50 µs before `poll(2)`. That window was measured against the macOS 1 KiB lockstep (3cc9cba0). On Linux, the same DOOM-fire pass with the spin set to 0 (env-gated local patch, not committed): | spin | load | fps | reader user | reader sys | reads | |---|---|---|---|---|---| | 50 µs | 21.1 / 17.6 / 13.0 | 648 / 936 / 954 | 1.43 / 2.03 / 1.73 s | 2.25 / 3.04 / 3.18 s | 1.04 / 1.56 / 1.47 M | | 0 | 20.5 / 14.0 / 10.5 | 901 / 918 / 962 | 0.31 / 0.27 / 0.37 s | 3.29 / 3.31 / 3.47 s | 1.19 / 1.16 / 1.25 M | The frame rate is unchanged within noise, and reader user time drops by 1.4-1.7 s per 12 s, about 7% of the daemon. 2. **Tiny reads on line-heavy output.** On `scrolling` the reader does 13-16 bytes per `read(2)`, about 1.2 M reads/s, with 8-9.7 s of sys time per 12 s. The spin makes no difference there: the data is always present in 13-byte pieces. A local patch that sleeps 20 µs after a read under 256-2048 bytes while the parser is busy cut the reader from about 9.9 s to 0.76 s per 12 s (-92%), with scrolling medians 78-99 ms against 89-109 ms. The same back-off applied unconditionally starves the parser under DOOM-fire (933 → 400 fps; 4 KiB is the ceiling of one PTY read on Linux, `N_TTY_BUF_SIZE`), so a real fix must back off only while the parser still has a backlog. Details in #400. 3. **SGR style interning, 21% of the parser under DOOM-fire.** Every SGR re-interns the whole `Attributes` through the hash map (hash plus equality). A one-entry cache for the last `(Attributes, StyleId)`, or skipping the intern when the SGR left the pen unchanged, removes most of that for streams that repeat colors. Expected gain: up to about 15-20% of parser time on DOOM-fire. 4. **CSI parameter parsing (`Params::push_run`)**, 10.7% of the parser: the next parser-side candidate after interning. 5. Ruled out: **the #380 flood-drain yield and parse-lock hand-off.** All tokio workers together spend 0.41 s per 15 s of DOOM-fire (2% of the daemon), and the parser thread made about 190 voluntary context switches per second (2,858 in 15 s), so the hand-off is not a wakeup storm. 6. Ruled out: **per-paint client-update encoding.** `wire::encode_row` plus `put_attr_run` are 0.46% of all samples. 7. Ruled out: **reader→parser copies.** `memmove` is 0.26% of samples. The copy into the swap buffer is negligible next to the syscall cost. Expected combined gain on Linux: removing most of the reader cost (items 1-2) takes about 25-55% off daemon CPU depending on the workload (5.75 of 20.3 s on DOOM-fire, 71.5 of 124 s on vtebench), which would put felis's vtebench total (132 s published) under alacritty's 104 s. Item 3 is a further 10-15% of daemon CPU on DOOM-fire. Before landing either, re-measure on a quiet host, and on macOS, where the spin was a measured win.

natsukium referenced this issue 2026-09-25 02:47:23 +09:00

daemon: Linux vtebench scrolling rows trail the peers and vary 25-50% between rounds #400

natsukium referenced this issue 2026-09-25 03:57:35 +09:00

skills: start the daemon in the samply and drive.sh harnesses #413

natsukium referenced this issue 2026-09-25 05:31:27 +09:00

grid: re-interning the pen on every SGR costs 21% of the parse thread under DOOM-fire #416

natsukium referenced this issue 2026-09-25 05:31:28 +09:00

vt: CSI parameter parsing is 10.7% of the parse thread under DOOM-fire #417

natsukium referenced this issue from a pull request that will close it, 2026-09-25 07:07:11 +09:00

pty: park the Linux PTY reader in poll(2) without spinning #421

natsukium referenced this issue 2026-09-25 07:07:34 +09:00

daemon: Linux vtebench scrolling rows trail the peers and vary 25-50% between rounds #400

natsukium closed this issue 2026-09-25 08:46:58 +09:00

Commenting is not possible because the repository is archived.

No Branch/Tag specified

Branches Tags

main

v0.1.0-rc.9

v0.1.0-rc.8

v0.1.0-rc.7

v0.1.0-rc.6

v0.1.0-rc.5

v0.1.0-rc.4

v0.1.0-rc.3

v0.1.0-rc.2

v0.1.0-rc.1

Labels

Clear labels   

priority/P0

Must be resolved before the v0.1.0 tag

  

priority/P1

Must be settled before the first public contract freezes

  

priority/P2

Explicitly deferred until after v0.1.0

  

release/v0.1.0

Work tracked for the first tagged release

  

status/blocked

Cannot start now: waits on an upstream release, another issue, or a recorded revisit trigger

  

status/planned

Triaged with a source-grounded plan and a passed pi review; ready to implement

  

type/bug

Shipped behavior that contradicts the docs or the code's own intent; needs a product code change

  

type/design

An open scope or trade-off question; needs a recorded decision in the owning explanation doc before code

  

type/test-gap

Documented or reviewed behavior that no test pins; usually split from a review finding, needs no product code change

  

type/tracker

Parent issue that tracks child work

No labels

priority/P0

priority/P1

priority/P2

release/v0.1.0

status/blocked

status/planned

type/bug

type/design

type/test-gap

type/tracker

Milestone

Clear milestone

No items

No milestone

Projects

Clear projects

No items

No project

Assignees

Clear assignees

No assignees

1 participant

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference

natsukium/felis#399

No description provided.