From 07f053a04ed49b272b0a8fe4f549819ac9b77525 Mon Sep 17 00:00:00 2001 From: Shivang Date: Wed, 26 Aug 2026 20:19:18 -0700 Subject: [PATCH 01/10] perf: add a glass-to-pixel latency probe The benchmark suite measures how fast the emulator consumes bytes, and by that measure BossTerm already beats iTerm2 and Alacritty. It says nothing about the interval that decides whether a terminal feels snappy: PTY arrival to the pixel that byte produces. That interval holds the redraw debounce, the data-stream poll timeout and the whole paint pass, and an emulator can parse 1.6 GB/s while still waiting 50 ms before drawing any of it. FrameLatencyProbe measures it. Gated on BOSSTERM_FRAME_PROBE=1; inert otherwise, with no timestamps taken and no allocation on any hot path. A daemon thread writes JSON to ~/.bossterm/frame-probe.json once a second. Four series: byteToPaintMs arrival to end of the paint that first draws it paintCostMs wall time inside renderTerminal lockedCaptureMs UI-thread time holding the terminal buffer lock drawCallsPerFrame drawText invocations per paint Arrival is stamped in BlockingTerminalDataStream rather than in the PTY reader, so it covers every producer (PTY, daemon bridge, share) and, more importantly, sits ahead of the queue wait: whatever performanceMode spends polling lands inside the measurement instead of hidden before it. byteToPaintMs is measured to draw-issued, not to photons, so it is a lower bound that excludes present and vsync. Two builds compared the same way are sound; an absolute latency claim needs the external camera anchor the README describes. Also adds BOSSTERM_REDRAW_DEBOUNCE_MS and BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS so one process can A/B the debounce against the same warmed JIT and window geometry. Both unset means the build behaves exactly as shipped, so a run with no env is a true baseline. This scaffolding comes out once the question settles. Histogram uses eight sub-buckets per octave and reports bucket floors, so every number is a slight under-estimate: it cannot manufacture an improvement that is not there. The bucketing is tested rather than trusted, and the earliest-arrival rule is mutation-checked - last-wins would under-report exactly when output is bursty, which is when it matters. --- benchmark/latency/README.md | 82 +++++ benchmark/latency/probe.sh | 69 ++++ benchmark/latency/workloads.sh | 80 +++++ .../compose/ComposeTerminalDisplay.kt | 26 +- .../compose/rendering/FrameLatencyProbe.kt | 322 ++++++++++++++++++ .../rendering/TerminalCanvasRenderer.kt | 10 + .../terminal/BlockingTerminalDataStream.kt | 39 ++- .../bossterm/compose/ui/ProperTerminal.kt | 3 + .../rendering/FrameLatencyProbeTest.kt | 135 ++++++++ 9 files changed, 759 insertions(+), 7 deletions(-) create mode 100644 benchmark/latency/README.md create mode 100755 benchmark/latency/probe.sh create mode 100755 benchmark/latency/workloads.sh create mode 100644 compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt create mode 100644 compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbeTest.kt diff --git a/benchmark/latency/README.md b/benchmark/latency/README.md new file mode 100644 index 000000000..69cb1ae76 --- /dev/null +++ b/benchmark/latency/README.md @@ -0,0 +1,82 @@ +# Glass-to-pixel latency harness + +The suite in `benchmark/` measures how fast the emulator **consumes** bytes: `cat` a file, +time how long it takes to return. Every number in `benchmark_results/` is of that shape. + +None of it can see the interval that decides whether a terminal feels snappy - the time +between a byte landing in the PTY and the pixel that byte produces. That interval holds the +redraw debounce, the data-stream poll timeout and the whole paint pass, and it is invisible +to a throughput benchmark: an emulator can parse 1.6 GB/s and still wait 50 ms before +drawing any of it. + +This harness measures that interval. + +## What is measured + +Build with the probe compiled in (it always is; it is inert unless the env flag is set) and +launch with `BOSSTERM_FRAME_PROBE=1`. A daemon thread then writes a JSON snapshot once a +second to `~/.bossterm/frame-probe.json`: + +| Field | Meaning | +|---|---| +| `byteToPaintMs` | PTY chunk arrival to the end of the paint pass that first draws it. The number a user feels. | +| `paintCostMs` | Wall time inside `renderTerminal`. Decides whether a throttle is needed at all. | +| `lockedCaptureMs` | UI-thread time holding the terminal buffer lock to capture a frame. Expected to grow with scrollback depth. | +| `drawCallsPerFrame` | `drawText` invocations per paint. The multiplier on text layout cost. | +| `idleFrames` | Paints that drew no newly-arrived data (blink, resize, selection, scroll). | + +Each is `{n, p50, p95, p99, max, mean}`. Latencies are milliseconds. **Report percentiles, +never means** - the tail is what gets noticed. + +### The honest caveat + +`byteToPaintMs` is measured to *draw-issued*, not to photons. It excludes GPU present and +vsync, so it is a **lower bound** on real latency. Two builds measured the same way compare +soundly; an absolute claim about "how many milliseconds a user waits" does not follow from +this number alone and needs the external anchor below. + +## Running it + +```bash +# 1. Launch with the probe on. The user runs the app; nothing here launches it. +BOSSTERM_FRAME_PROBE=1 ./gradlew :bossterm-app:run --no-daemon + +# 2. Zero the histograms immediately before a workload. +./benchmark/latency/probe.sh reset + +# 3. Run one workload in the BossTerm window under test. +./benchmark/latency/workloads.sh keystrokes # (a) 200 single keypresses at a prompt +./benchmark/latency/workloads.sh bulk # (b) cat a 5 MB log +./benchmark/latency/workloads.sh tui # (c) full-screen redraw loop +./benchmark/latency/workloads.sh scroll # (d) full-screen scroll +./benchmark/latency/workloads.sh aged # (e) (b) again, after 10k lines of scrollback + +# 4. Read the result. +./benchmark/latency/probe.sh show +``` + +Workload (e) is the one that exposes scrollback-dependent cost: run it in the *same* tab as +a preceding `bulk`, never a fresh one. + +## A/B without a rebuild + +Two configurations can be compared inside one process, against the same warmed JIT and the +same window geometry, which removes the largest source of run-to-run noise: + +| Knob | Baseline | Alternative | +|---|---|---| +| `BOSSTERM_REDRAW_DEBOUNCE_MS` | unset (8 ms) | `0` | +| `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS` | unset (50 ms) | `0` | +| `performanceMode` in `~/.bossterm/settings.json` | `balanced` | `latency` | + +The two env vars are measurement scaffolding and are removed once the debounce question is +settled. With neither set, the build behaves exactly as shipped, so a run with no env is a +true baseline. + +## External anchor - do this once + +The in-process number is a proxy. Before any conclusion rests on it, confirm it tracks +reality: film ~10 keypresses at a shell prompt with a phone at 240 fps, count frames from +key-down to the glyph appearing, and compare the median against `byteToPaintMs.p50` plus one +frame of present. If they disagree by more than a frame, the probe is wrong and gets fixed +before any tuning decision is made on it. diff --git a/benchmark/latency/probe.sh b/benchmark/latency/probe.sh new file mode 100755 index 000000000..a103b48f8 --- /dev/null +++ b/benchmark/latency/probe.sh @@ -0,0 +1,69 @@ +#!/usr/bin/env bash +# Read and reset the BossTerm frame-latency probe. +# +# The probe writes a JSON snapshot once a second to $BOSSTERM_FRAME_PROBE_OUT, or +# ~/.bossterm/frame-probe.json by default. It only runs when the app was launched with +# BOSSTERM_FRAME_PROBE=1; without that, the file never appears. +set -euo pipefail + +OUT="${BOSSTERM_FRAME_PROBE_OUT:-$HOME/.bossterm/frame-probe.json}" +RESET="$(dirname "$OUT")/frame-probe.reset" + +usage() { + cat <&2 + echo "launch the app with BOSSTERM_FRAME_PROBE=1 and give it a second to sample" >&2 + exit 1 + fi +} + +case "${1:-}" in + reset) + require_snapshot + before=$(stat -f %m "$OUT" 2>/dev/null || stat -c %Y "$OUT") + touch "$RESET" + # The sampler deletes the marker as it zeroes. Waiting for that, rather than + # returning immediately, is what stops a workload from starting against counters + # that still hold the previous run. + for _ in $(seq 1 50); do + if [[ ! -f "$RESET" ]]; then + now=$(stat -f %m "$OUT" 2>/dev/null || stat -c %Y "$OUT") + if [[ "$now" != "$before" ]]; then + echo "reset confirmed" + exit 0 + fi + fi + sleep 0.2 + done + echo "reset marker was not consumed within 10s - is the app running with BOSSTERM_FRAME_PROBE=1?" >&2 + exit 1 + ;; + show) + require_snapshot + cat "$OUT" + ;; + watch) + require_snapshot + while true; do + date +%H:%M:%S + cat "$OUT" + echo + sleep 1 + done + ;; + path) echo "$OUT" ;; + *) usage; exit 1 ;; +esac diff --git a/benchmark/latency/workloads.sh b/benchmark/latency/workloads.sh new file mode 100755 index 000000000..241d731e6 --- /dev/null +++ b/benchmark/latency/workloads.sh @@ -0,0 +1,80 @@ +#!/usr/bin/env bash +# Fixed workloads for the frame-latency probe. +# +# Run these INSIDE the BossTerm tab being measured, with the probe reset immediately +# beforehand (`probe.sh reset`). Each one is deterministic so two builds see identical work. +# +# Scope note: the probe stamps a chunk when it ARRIVES from the PTY, so everything here +# measures the output half of the loop (arrival -> pixel). The input half (keypress -> +# PTY write) is not covered by any of these and needs the external camera anchor described +# in README.md. `interactive` is the closest proxy: isolated single-character writes, which +# is the shape a shell echo has, and the case the redraw debounce penalises hardest. +set -euo pipefail + +DURATION_TUI="${DURATION_TUI:-10}" +FIXTURE_DIR="${TMPDIR:-/tmp}/bossterm-latency" +mkdir -p "$FIXTURE_DIR" + +make_log() { + local path="$FIXTURE_DIR/bulk-5mb.log" + if [[ ! -f "$path" ]]; then + # Deterministic content, mixed line lengths and some ANSI colour so the run + # exercises style runs rather than one uniform batch. + awk 'BEGIN { + for (i = 0; i < 60000; i++) { + printf "\033[32m%06d\033[0m INFO module-%02d request completed in %3d ms path=/api/v1/resource/%d\n", i, i % 32, i % 250, i + } + }' > "$path" + fi + echo "$path" +} + +case "${1:-}" in + interactive) + # 200 isolated single-character writes, 50 ms apart. Each one is its own PTY chunk, + # so each pays the full arrival-to-paint cost with no batching to hide behind. + for _ in $(seq 1 200); do + printf 'x' + sleep 0.05 + done + printf '\n' + ;; + bulk) + cat "$(make_log)" + ;; + tui) + # Full-screen repaint loop on the alternate screen: the regime that trips + # HIGH_VOLUME mode (>100 redraws/sec) and drops the terminal to 20 fps. + printf '\033[?1049h' + end=$(( SECONDS + DURATION_TUI )) + frame=0 + while (( SECONDS < end )); do + printf '\033[H' + for row in $(seq 1 40); do + printf '\033[%dm row %02d frame %06d %s\033[0m\n' \ + $(( 31 + (row + frame) % 7 )) "$row" "$frame" \ + 'the quick brown fox jumps over the lazy dog 0123456789' + done + frame=$(( frame + 1 )) + sleep 0.02 + done + printf '\033[?1049l' + echo "tui: $frame frames in ${DURATION_TUI}s" + ;; + scroll) + # Continuous single-line scrolling: every chunk shifts the whole viewport. + for i in $(seq 1 5000); do + printf '\033[36m%05d\033[0m scrolling line with enough width to fill a normal terminal column count\n' "$i" + done + ;; + aged) + # Finding E: the per-frame snapshot walks screen AND full history, so cost is + # expected to rise with scrollback depth. Run in the SAME tab, never a fresh one. + seq 1 10000 | sed 's/^/scrollback filler line /' + cat "$(make_log)" + ;; + *) + echo "usage: workloads.sh {interactive|bulk|tui|scroll|aged}" >&2 + exit 1 + ;; +esac diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt index d5de559b4..d01ef2520 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt @@ -23,6 +23,12 @@ import java.util.concurrent.atomic.AtomicReference * based on output rate to reduce redraws by 51-91% for medium/large files * while maintaining zero latency for interactive use. */ +private val interactiveDebounceOverrideMs: Long? = + System.getenv("BOSSTERM_REDRAW_DEBOUNCE_MS")?.toLongOrNull()?.coerceAtLeast(0L) + +private val highVolumeDebounceOverrideMs: Long? = + System.getenv("BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS")?.toLongOrNull()?.coerceAtLeast(0L) + class ComposeTerminalDisplay : TerminalDisplay { // ===== ADAPTIVE DEBOUNCING (Phase 2) ===== @@ -35,6 +41,24 @@ class ComposeTerminalDisplay : TerminalDisplay { IMMEDIATE(0L, "Instant for keyboard/mouse input") } + /** + * Effective debounce for [mode], with a measurement-time override. + * + * MEASUREMENT SCAFFOLDING - to be removed once the debounce question is settled. + * `BOSSTERM_REDRAW_DEBOUNCE_MS` and `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS` let a single + * build A/B the wait without a rebuild-and-relaunch between every sample, which is the + * only way to compare two configurations against the same warmed JIT, the same window + * size and the same shell history. Unset, both fall through to the shipped constants, + * so a run with no env set is a true baseline. + * + * `delay(0)` returns without suspending, so an override of 0 costs no dispatch hop. + */ + private fun debounceMsFor(mode: RedrawMode): Long = when (mode) { + RedrawMode.INTERACTIVE -> interactiveDebounceOverrideMs ?: mode.debounceMs + RedrawMode.HIGH_VOLUME -> highVolumeDebounceOverrideMs ?: mode.debounceMs + RedrawMode.IMMEDIATE -> mode.debounceMs + } + /** * Redraw request with priority. */ @@ -357,7 +381,7 @@ class ComposeTerminalDisplay : TerminalDisplay { RedrawPriority.NORMAL -> { val mode = detectAndUpdateMode() - delay(mode.debounceMs) + delay(debounceMsFor(mode)) // Re-check sync mode after debounce delay: a new ?2026h may // have been processed by the emulator while we were waiting. diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt new file mode 100644 index 000000000..1a7089e63 --- /dev/null +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt @@ -0,0 +1,322 @@ +package ai.rever.bossterm.compose.rendering + +import java.io.File +import java.util.concurrent.atomic.AtomicInteger +import java.util.concurrent.atomic.AtomicLong +import java.util.concurrent.atomic.AtomicLongArray + +/** + * Opt-in glass-to-pixel latency instrumentation, gated on `BOSSTERM_FRAME_PROBE=1`. + * + * The existing `benchmark/` suite measures how fast the emulator *consumes* bytes - it + * cannot see the time between a byte landing in the PTY and the pixel that byte produces. + * That interval is where the redraw debounce, the data-stream poll timeout and the paint + * cost all live, so it needs its own measurement before any of them are touched. + * + * What each series means: + * + * - [byteToPaint] - a PTY chunk's arrival (stamped in `BlockingTerminalDataStream.append`, + * before the queue wait) to the end of the paint pass that first draws it. This is the + * number a user feels. It is *draw-issued*, not photons: it excludes GPU present and + * vsync, so it is a lower bound on real latency and must be anchored against an external + * capture before any conclusion rests on the absolute value. Deltas between two builds + * measured the same way are sound regardless. + * - [paintCost] - wall time inside `renderTerminal`. The number that decides whether a + * throttle is needed at all. + * - [snapshotCost] - wall time the UI thread spends holding the terminal buffer lock to + * capture a frame. Expected to scale with scrollback depth, which is the shape that + * makes a long-lived session feel worse than a fresh one. + * - [drawCallsPerFrame] - `drawText` invocations per paint. The multiplier on text layout. + * + * All recording happens on the UI thread (the paint pass); [markArrival] is the one method + * called from the PTY/emulator threads and only performs a CAS. + * + * When disabled, every method here is an `enabled` check and a return, and no timestamps + * are taken. Nothing in this file allocates on the hot path. + */ +object FrameLatencyProbe { + + const val ENV_FLAG: String = "BOSSTERM_FRAME_PROBE" + + /** Sentinel for "no un-rendered chunk is pending". */ + private const val NONE = Long.MIN_VALUE + + /** + * Whether any measurement happens at all. + * + * Seeded from the environment and settable only from this module, so tests can exercise + * the recording paths without a process-wide env var. Nothing in production flips it: + * the sampler thread is started from `init` against the env-derived value, so a later + * write enables recording but never spawns a writer. + */ + @Volatile + var enabled: Boolean = System.getenv(ENV_FLAG).let { it == "1" || it.equals("true", ignoreCase = true) } + internal set + + /** + * Arrival time of the oldest PTY chunk not yet drawn, or [NONE]. + * + * Only the *oldest* is kept: a paint draws the whole buffer, so a frame that renders + * chunk N also renders every chunk before it, and the latency that matters is the one + * the earliest byte experienced. Later arrivals inside the same frame lose the CAS and + * are deliberately dropped rather than overwriting an older, worse sample. + */ + private val pendingArrival = AtomicLong(NONE) + + /** Reset per paint by [beginFrame], read by [endFrame]. */ + private val drawCalls = AtomicInteger(0) + + val byteToPaint: Histogram = Histogram() + val paintCost: Histogram = Histogram() + val snapshotCost: Histogram = Histogram() + val drawCallsPerFrame: Histogram = Histogram() + + /** Paints that drew no newly-arrived data (blink, resize, selection, scroll). */ + private val idleFrames = AtomicLong(0) + + private val startedAtNanos = System.nanoTime() + + /** + * Where the sampler writes. Overridable so two builds can be measured into separate + * files in one scripted run. + */ + private val outFile: File = + File(System.getenv("BOSSTERM_FRAME_PROBE_OUT") ?: "${System.getProperty("user.home")}/.bossterm/frame-probe.json") + + /** + * Touch this file to zero the histograms before a workload; the sampler consumes and + * deletes it. A file rather than a signal or an MCP tool because the probe must add no + * product surface: nothing here is reachable, or even constructed, without the env flag. + */ + private val resetFile: File = File(outFile.absoluteFile.parentFile, "frame-probe.reset") + + init { + if (enabled) startSampler() + } + + private fun startSampler() { + Runtime.getRuntime().addShutdownHook(Thread({ writeSnapshotQuietly() }, "frame-probe-final")) + Thread({ + while (true) { + try { + Thread.sleep(SAMPLE_INTERVAL_MS) + if (resetFile.exists()) { + resetFile.delete() + reset() + } + writeSnapshotQuietly() + } catch (_: InterruptedException) { + return@Thread + } catch (_: Throwable) { + // A diagnostic must never take the app down. Keep sampling. + } + } + }, "frame-probe-sampler").apply { isDaemon = true }.start() + } + + private fun writeSnapshotQuietly() { + runCatching { + val dir = outFile.absoluteFile.parentFile + dir?.mkdirs() + val tmp = File(dir, outFile.name + ".tmp") + tmp.writeText(json()) + // Atomic rename so a reader never sees a half-written file. + if (!tmp.renameTo(outFile)) { + outFile.writeText(json()) + tmp.delete() + } + } + } + + /** Machine-readable snapshot. Latencies in milliseconds. */ + fun json(): String = buildString { + append("{\n") + append(" \"enabled\": ").append(enabled).append(",\n") + append(" \"uptimeSeconds\": ") + .append(String.format(java.util.Locale.ROOT, "%.1f", (System.nanoTime() - startedAtNanos) / 1e9)) + .append(",\n") + append(" \"byteToPaintMs\": ").append(byteToPaint.jsonMillis()).append(",\n") + append(" \"paintCostMs\": ").append(paintCost.jsonMillis()).append(",\n") + append(" \"lockedCaptureMs\": ").append(snapshotCost.jsonMillis()).append(",\n") + append(" \"drawCallsPerFrame\": ").append(drawCallsPerFrame.jsonRaw()).append(",\n") + append(" \"idleFrames\": ").append(idleFrames.get()).append("\n") + append("}\n") + } + + private const val SAMPLE_INTERVAL_MS = 1_000L + + /** + * Stamp a PTY chunk's arrival. Called from the data stream the moment a chunk is + * handed over, ahead of the queue wait, so the poll timeout is inside the measurement + * rather than hidden before it. + */ + fun markArrival(nanos: Long) { + if (!enabled) return + // Keep the earliest pending arrival; a later chunk must not reset the clock. + pendingArrival.compareAndSet(NONE, nanos) + } + + /** Timestamp for a later `record*` call, or 0 when the probe is off. */ + fun startTiming(): Long = if (enabled) System.nanoTime() else 0L + + /** Start of a paint pass. Returns the start timestamp to hand back to [endFrame]. */ + fun beginFrame(): Long { + if (!enabled) return 0L + drawCalls.set(0) + return System.nanoTime() + } + + /** End of a paint pass. [startNanos] is whatever [beginFrame] returned. */ + fun endFrame(startNanos: Long) { + if (!enabled) return + val now = System.nanoTime() + paintCost.recordNanos(now - startNanos) + drawCallsPerFrame.record(drawCalls.get().toLong()) + val arrival = pendingArrival.getAndSet(NONE) + if (arrival == NONE) idleFrames.incrementAndGet() else byteToPaint.recordNanos(now - arrival) + } + + /** + * Wall time the UI thread spent holding the terminal buffer lock to capture a frame. + * + * The whole locked region, not just `createIncrementalSnapshot`, because the cost that + * matters is how long the emulator is blocked - and it is the same region either way. + */ + fun recordSnapshot(startNanos: Long) { + if (!enabled) return + snapshotCost.recordNanos(System.nanoTime() - startNanos) + } + + /** One `drawText` issued by the current paint. */ + fun countDrawCall() { + if (!enabled) return + drawCalls.incrementAndGet() + } + + /** Drop every sample. Call between workloads so runs do not contaminate each other. */ + fun reset() { + byteToPaint.reset() + paintCost.reset() + snapshotCost.reset() + drawCallsPerFrame.reset() + idleFrames.set(0) + pendingArrival.set(NONE) + drawCalls.set(0) + } + + /** Human-readable report. Latencies in milliseconds, draw calls as raw counts. */ + fun report(): String = buildString { + appendLine("BossTerm frame probe (enabled=$enabled)") + if (!enabled) { + appendLine(" Set $ENV_FLAG=1 before launching to collect samples.") + return@buildString + } + appendLine(" byte->paint ${byteToPaint.summaryMillis()}") + appendLine(" paint cost ${paintCost.summaryMillis()}") + appendLine(" snapshot cost ${snapshotCost.summaryMillis()}") + appendLine(" drawText/frame ${drawCallsPerFrame.summaryRaw()}") + appendLine(" frames with no new data: ${idleFrames.get()}") + appendLine(" NOTE: byte->paint is draw-issued, excluding GPU present and vsync.") + } + + /** + * Fixed-bucket log histogram: eight sub-buckets per octave, so a reported value is + * never more than 1/8 below the true one. (Four sub-buckets would be 1/4, since the + * widest bucket relative to its own floor is the first in an octave: width 2^k/N at + * value 2^k.) Chosen over storing raw samples because recording sits in the paint + * pass - it must not allocate, and must not grow without bound over a long soak. + * + * Quantiles report the bucket FLOOR, so every number this produces is a slight + * under-estimate. That is the safe direction for a latency claim: it cannot manufacture + * an improvement that is not there. + */ + class Histogram { + private val counts = AtomicLongArray(BUCKETS) + private val total = AtomicLong(0) + private val sum = AtomicLong(0) + private val max = AtomicLong(0) + + fun recordNanos(nanos: Long) = record(nanos / 1_000) + + fun record(value: Long) { + val v = if (value < 0) 0 else value + counts.incrementAndGet(indexOf(v)) + total.incrementAndGet() + sum.addAndGet(v) + max.accumulateAndGet(v) { a, b -> if (a >= b) a else b } + } + + fun reset() { + for (i in 0 until BUCKETS) counts.set(i, 0) + total.set(0) + sum.set(0) + max.set(0) + } + + fun count(): Long = total.get() + + /** Lower bound of the bucket holding the [q]th quantile, in the recorded unit. */ + fun quantile(q: Double): Long { + val n = total.get() + if (n == 0L) return 0 + val target = Math.ceil(q * n).toLong().coerceIn(1, n) + var seen = 0L + for (i in 0 until BUCKETS) { + seen += counts.get(i) + if (seen >= target) return valueOf(i) + } + return max.get() + } + + fun summaryMillis(): String { + val n = count() + if (n == 0L) return "no samples" + fun ms(us: Long) = String.format(java.util.Locale.ROOT, "%.2f", us / 1000.0) + return "n=$n p50=${ms(quantile(0.50))} p95=${ms(quantile(0.95))} " + + "p99=${ms(quantile(0.99))} max=${ms(max.get())} mean=${ms(sum.get() / n)} (ms)" + } + + /** `{"n":..,"p50":..,...}` with microsecond samples rendered as milliseconds. */ + fun jsonMillis(): String = json { us -> String.format(java.util.Locale.ROOT, "%.3f", us / 1000.0) } + + /** Same shape, but the samples are plain counts rather than durations. */ + fun jsonRaw(): String = json { it.toString() } + + private fun json(fmt: (Long) -> String): String { + val n = count() + if (n == 0L) return "{\"n\": 0}" + return "{\"n\": $n, \"p50\": ${fmt(quantile(0.50))}, \"p95\": ${fmt(quantile(0.95))}, " + + "\"p99\": ${fmt(quantile(0.99))}, \"max\": ${fmt(max.get())}, \"mean\": ${fmt(sum.get() / n)}}" + } + + fun summaryRaw(): String { + val n = count() + if (n == 0L) return "no samples" + return "n=$n p50=${quantile(0.50)} p95=${quantile(0.95)} " + + "p99=${quantile(0.99)} max=${max.get()} mean=${sum.get() / n}" + } + + private companion object { + /** 8 sub-buckets per octave; see the class doc for the resulting bound. */ + const val SUB_BITS = 3 + const val SUB_COUNT = 1 shl SUB_BITS + const val SUB_MASK = (SUB_COUNT - 1).toLong() + const val BUCKETS = 256 + + fun indexOf(v: Long): Int { + if (v < SUB_COUNT) return v.toInt() + val octave = 63 - java.lang.Long.numberOfLeadingZeros(v) + val sub = (v ushr (octave - SUB_BITS)) and SUB_MASK + val index = ((octave - SUB_BITS + 1) shl SUB_BITS) + sub.toInt() + return if (index >= BUCKETS) BUCKETS - 1 else index + } + + fun valueOf(index: Int): Long { + if (index < SUB_COUNT) return index.toLong() + val octave = (index ushr SUB_BITS) - 1 + SUB_BITS + val sub = (index and (SUB_COUNT - 1)).toLong() + return (SUB_COUNT.toLong() or sub) shl (octave - SUB_BITS) + } + } + } +} diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt index a9db675dd..c41cbfdfa 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt @@ -549,6 +549,7 @@ object TerminalCanvasRenderer { style: TextStyle ) { if (topLeft.x >= size.width || topLeft.y >= size.height) return + FrameLatencyProbe.countDrawCall() drawText( textMeasurer = textMeasurer, text = text, @@ -566,6 +567,15 @@ object TerminalCanvasRenderer { * */ fun DrawScope.renderTerminal(ctx: RenderingContext) { + val probeStart = FrameLatencyProbe.beginFrame() + try { + renderTerminalPasses(ctx) + } finally { + FrameLatencyProbe.endFrame(probeStart) + } + } + + private fun DrawScope.renderTerminalPasses(ctx: RenderingContext) { // Cache character analysis to avoid redundant computation between passes val analysisCache = AnalysisCache(ctx.visibleRows, ctx.visibleCols) diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt index 91e38adda..1a69a10d5 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt @@ -1,10 +1,12 @@ package ai.rever.bossterm.compose.terminal +import ai.rever.bossterm.compose.rendering.FrameLatencyProbe import ai.rever.bossterm.terminal.TerminalDataStream import ai.rever.bossterm.terminal.util.GraphemeUtils import ai.rever.bossterm.terminal.util.GraphemeBoundaryUtils import java.io.IOException import java.util.concurrent.BlockingQueue +import java.util.concurrent.ConcurrentLinkedQueue import java.util.concurrent.LinkedBlockingQueue import java.util.concurrent.TimeUnit @@ -59,6 +61,31 @@ class BlockingTerminalDataStream( private val buffer = StringBuilder() private var position = 0 private val dataQueue: BlockingQueue = LinkedBlockingQueue() + + /** + * Arrival timestamps for the chunks in [dataQueue], one per entry, in the same order. + * + * Kept alongside rather than inside the queue so the shipped type stays `String` and + * nothing on the hot path changes when [FrameLatencyProbe] is off - the queue is only + * ever written under `FrameLatencyProbe.enabled`. Stamped here, before the poll wait + * below, so that whatever the performance mode spends waiting lands inside the + * measurement instead of ahead of it. + */ + private val arrivalNanos = ConcurrentLinkedQueue() + + /** Offer a chunk plus, when probing, its arrival time. Keeps the two queues aligned. */ + private fun enqueue(chunk: String) { + if (FrameLatencyProbe.enabled) arrivalNanos.offer(System.nanoTime()) + dataQueue.offer(chunk) + } + + /** Pair every successful take from [dataQueue] with its arrival stamp. */ + private fun took(chunk: String?): String? { + if (FrameLatencyProbe.enabled && chunk != null && chunk != CLOSE_SENTINEL) { + arrivalNanos.poll()?.let(FrameLatencyProbe::markArrival) + } + return chunk + } @Volatile private var closed = false private val pushBackStack = mutableListOf() @@ -174,14 +201,14 @@ class BlockingTerminalDataStream( val completeData = fullData.substring(0, lastCompleteIndex) if (completeData.isNotEmpty()) { - dataQueue.offer(completeData) + enqueue(completeData) // Invoke debug callback only for complete data debugCallback?.invoke(completeData) notifyRawOutput(completeData) } } else { // All graphemes are complete - dataQueue.offer(fullData) + enqueue(fullData) debugCallback?.invoke(fullData) notifyRawOutput(fullData) } @@ -223,7 +250,7 @@ class BlockingTerminalDataStream( onTerminalStateChanged?.invoke() // Need more data - behavior depends on performance mode (issue #146) - val chunk = if (closed) { + val chunk = took(if (closed) { dataQueue.poll() // Non-blocking if closed } else { when (performanceMode) { @@ -236,7 +263,7 @@ class BlockingTerminalDataStream( // BALANCED: Poll with 10ms timeout as middle ground PerformanceMode.BALANCED -> dataQueue.poll(10, TimeUnit.MILLISECONDS) } - } + }) // Check for close sentinel if (chunk == CLOSE_SENTINEL) { @@ -286,14 +313,14 @@ class BlockingTerminalDataStream( // Compact buffer to prevent memory leak (issue #179) compactBuffer() - val chunk = when (performanceMode) { + val chunk = took(when (performanceMode) { // LATENCY: Non-blocking - return immediately with what we have PerformanceMode.LATENCY -> dataQueue.poll() // THROUGHPUT: Wait longer for better batching PerformanceMode.THROUGHPUT -> dataQueue.poll(10, TimeUnit.MILLISECONDS) // BALANCED: Short wait for moderate batching PerformanceMode.BALANCED -> dataQueue.poll(5, TimeUnit.MILLISECONDS) - } + }) if (chunk != null && chunk != CLOSE_SENTINEL) { buffer.append(chunk) } else { diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ui/ProperTerminal.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ui/ProperTerminal.kt index 6f6453df3..43f4b412f 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ui/ProperTerminal.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ui/ProperTerminal.kt @@ -91,6 +91,7 @@ import ai.rever.bossterm.compose.search.SearchBar import ai.rever.bossterm.compose.rendering.RenderingContext import ai.rever.bossterm.compose.rendering.RenderableBlock import ai.rever.bossterm.compose.rendering.ImageRenderer +import ai.rever.bossterm.compose.rendering.FrameLatencyProbe import ai.rever.bossterm.compose.rendering.TerminalCanvasRenderer import ai.rever.bossterm.terminal.model.TerminalLine import kotlin.math.abs @@ -2054,6 +2055,7 @@ fun ProperTerminal( // after it returns, never during. myLock is reentrant, so the nested acquisitions // below are free, and this replaces TWO acquisitions per composition with one: the // type-ahead column used to take it again, live, outside the capture entirely. + val probeCaptureStart = FrameLatencyProbe.startTiming() textBuffer.lock() try { // Type-ahead FIRST: its reset path clears predictions off the lines, and doing @@ -2068,6 +2070,7 @@ fun ProperTerminal( ) } finally { textBuffer.unlock() + FrameLatencyProbe.recordSnapshot(probeCaptureStart) } } } diff --git a/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbeTest.kt b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbeTest.kt new file mode 100644 index 000000000..9e78aca38 --- /dev/null +++ b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbeTest.kt @@ -0,0 +1,135 @@ +package ai.rever.bossterm.compose.rendering + +import kotlin.test.AfterTest +import kotlin.test.BeforeTest +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertTrue + +/** + * The probe exists to decide whether a latency change helped. A histogram that reports + * plausible-but-wrong percentiles would make every later measurement worthless while + * looking fine, so the bucketing is pinned here rather than trusted. + */ +class FrameLatencyProbeTest { + + private var wasEnabled = false + + @BeforeTest + fun setUp() { + wasEnabled = FrameLatencyProbe.enabled + FrameLatencyProbe.enabled = true + FrameLatencyProbe.reset() + } + + @AfterTest + fun tearDown() { + FrameLatencyProbe.reset() + FrameLatencyProbe.enabled = wasEnabled + } + + @Test + fun bucketsRoundTripWithinStatedError() { + // Four sub-buckets per octave puts the worst case at 1/8 of the value. A bucket + // that silently widened would show up as an under-reported p99, which is exactly + // the number a latency claim rests on. + val h = FrameLatencyProbe.Histogram() + var v = 1L + while (v < 4_000_000L) { + h.reset() + h.record(v) + val reported = h.quantile(0.5) + assertTrue( + reported <= v && v - reported <= v / 8 + 1, + "value $v reported as $reported, outside the 12.5% bucket bound" + ) + v = v * 3 / 2 + 1 + } + } + + @Test + fun quantilesTrackAKnownDistribution() { + val h = FrameLatencyProbe.Histogram() + // 990 samples at 1000, 10 at 100000. p50 and p95 must land on the body, p99 on it + // too (the 10 outliers are the top 1%, so p99 is the last body sample), and only + // max should see the tail. Getting this backwards is the classic percentile bug. + repeat(990) { h.record(1_000) } + repeat(10) { h.record(100_000) } + + assertEquals(1000L, h.count()) + assertWithinBucket(1_000, h.quantile(0.50)) + assertWithinBucket(1_000, h.quantile(0.95)) + assertWithinBucket(1_000, h.quantile(0.99)) + assertWithinBucket(100_000, h.quantile(1.0)) + } + + @Test + fun emptyHistogramReportsNothingRatherThanZeroLatency() { + val h = FrameLatencyProbe.Histogram() + assertEquals(0L, h.count()) + assertEquals(0L, h.quantile(0.5)) + assertTrue(h.jsonMillis().contains("\"n\": 0"), h.jsonMillis()) + // A reader must be able to tell "no samples" from "instant", or an unexercised + // build reads as a win. + assertTrue(!h.jsonMillis().contains("p50"), h.jsonMillis()) + } + + @Test + fun frameKeepsTheEarliestPendingArrival() { + // A paint draws the whole buffer, so it renders every chunk that arrived before it. + // The latency that matters is the one the OLDEST un-drawn chunk experienced; a + // later arrival overwriting it would under-report exactly when output is bursty. + val now = System.nanoTime() + FrameLatencyProbe.markArrival(now - 50_000_000L) // 50 ms ago + FrameLatencyProbe.markArrival(now - 1_000_000L) // 1 ms ago, must not win + + val start = FrameLatencyProbe.beginFrame() + FrameLatencyProbe.endFrame(start) + + assertEquals(1L, FrameLatencyProbe.byteToPaint.count()) + val p50 = FrameLatencyProbe.byteToPaint.quantile(0.5) + assertTrue(p50 >= 40_000, "expected roughly 50ms in microseconds, got $p50") + } + + @Test + fun aFrameWithNoNewDataIsNotCountedAsLatency() { + // Blink, resize and scroll all repaint without any byte having arrived. Recording + // those would flood the histogram with fabricated near-zero samples and drag every + // percentile down. + val start = FrameLatencyProbe.beginFrame() + FrameLatencyProbe.endFrame(start) + + assertEquals(0L, FrameLatencyProbe.byteToPaint.count()) + assertEquals(1L, FrameLatencyProbe.paintCost.count()) + } + + @Test + fun drawCallsAreCountedPerFrameNotCumulatively() { + repeat(3) { + val start = FrameLatencyProbe.beginFrame() + repeat(7) { FrameLatencyProbe.countDrawCall() } + FrameLatencyProbe.endFrame(start) + } + assertEquals(3L, FrameLatencyProbe.drawCallsPerFrame.count()) + assertEquals(7L, FrameLatencyProbe.drawCallsPerFrame.quantile(0.5)) + } + + @Test + fun disabledProbeRecordsNothing() { + FrameLatencyProbe.enabled = false + FrameLatencyProbe.markArrival(System.nanoTime() - 10_000_000L) + val start = FrameLatencyProbe.beginFrame() + FrameLatencyProbe.countDrawCall() + FrameLatencyProbe.endFrame(start) + + assertEquals(0L, FrameLatencyProbe.byteToPaint.count()) + assertEquals(0L, FrameLatencyProbe.paintCost.count()) + } + + private fun assertWithinBucket(expected: Long, actual: Long) { + assertTrue( + actual <= expected && expected - actual <= expected / 8 + 1, + "expected ~$expected, got $actual" + ) + } +} From 736b646b00e95c826e2e79076b10963c9833a430 Mon Sep 17 00:00:00 2001 From: Shivang Date: Wed, 26 Aug 2026 20:30:31 -0700 Subject: [PATCH 02/10] perf: cut per-cell and per-word work in the text pass, behind a flag Two reductions on the renderer's hottest loop, both gated on BOSSTERM_FAST_TEXT=1 so one process can A/B them against the same warmed JIT and window geometry as the baseline. Unset, the renderer behaves exactly as before. 1. ASCII neighbourhoods skip the sequence probes. Every cell currently builds a 20-character lookahead into a String and runs three scans over it, to decide whether a ZWJ sequence, a skin-tone modifier or a regional indicator starts here. All three are non-ASCII, and all three can only reach a cell from col..col+2 - checkFollowingSkinTone looks one ahead and steps over a DWC marker, checkRegionalIndicatorSequence needs the indicator at col itself, and a grapheme cluster can only pull a ZWJ in from the very next cell. So on a line of a log, a diff or source code, that work is dead, per cell, per frame. The soundness condition is one-directional: the fast path must never skip a probe that would have fired. PlainAsciiFastPathTest checks exactly that, over a corpus with ZWJ families, flags, skin tones, variation selectors and CJK, at every column - and separately that the guard still engages on ordinary text, since a fast path that never fires would pass the first check trivially. Narrowing the window to col..col alone makes both fail. 2. Blanks extend a batched run instead of breaking it. canBatch excluded ' ', so every space flushed the batch: aligned output, indented source and powerline prompts cost one drawText per WORD. A blank paints no glyph, so only an underline makes it visible - it can join a run whose underline state matches whatever colour or weight it nominally carries. It still may not start one, since leading blanks would move the origin and shape nothing. Trailing blanks are then trimmed before layout, since shaping invisible cells is pure cost, except under an underline where the blanks carry the rule. That trim is the one place this could drop a character that should have been drawn, so it is extracted as visibleRunLength and tested directly - interior blanks in particular must survive, or "a b" collapses to "a". NUL is mapped to a space on the way into the batch: appending it verbatim would hand the shaper a control character to draw. --- .../rendering/TerminalCanvasRenderer.kt | 105 ++++++++++--- .../rendering/PlainAsciiFastPathTest.kt | 138 ++++++++++++++++++ 2 files changed, 226 insertions(+), 17 deletions(-) create mode 100644 compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/PlainAsciiFastPathTest.kt diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt index c41cbfdfa..84b2467cd 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt @@ -438,6 +438,52 @@ internal fun imageCellSlice( ) } +/** + * MEASUREMENT SCAFFOLDING - `BOSSTERM_FAST_TEXT=1`. + * + * Gates the renderer-side reductions so one process can A/B them against the same warmed + * JIT, window geometry and shell history as the baseline. Rebuilding and relaunching between + * samples is the largest source of run-to-run noise in a latency measurement and it is + * avoidable here. The flag comes out, and the fast path becomes unconditional, once the + * numbers say what it is worth. + */ +private val fastTextPath: Boolean = + System.getenv("BOSSTERM_FAST_TEXT").let { it == "1" || it.equals("true", ignoreCase = true) } + +/** + * How much of a batched run actually needs shaping. + * + * A blank draws no glyph, so trailing blanks are invisible and laying them out is pure + * cost - and a run that is nothing but blanks need not be drawn at all. An underlined run + * is the exception: there the blanks carry the rule, so the full length stands. + * + * Separated out because this is the one place the blank-batching change could drop a + * character that should have been drawn. + */ +internal fun visibleRunLength(text: CharSequence, underlined: Boolean): Int { + if (underlined) return text.length + var length = text.length + while (length > 0 && text[length - 1] == ' ') length-- + return length +} + +/** + * True when no multi-cell grapheme cluster can begin at, or reach into, [col]. + * + * ZWJ (U+200D), the skin-tone modifiers (U+1F3FB..U+1F3FF) and the regional indicators + * (U+1F1E6..U+1F1FF) are all non-ASCII, and all three can only reach this cell from + * `col..col + 2`: `checkFollowingSkinTone` looks one ahead and steps over a DWC marker, and + * `checkRegionalIndicatorSequence` requires the indicator to sit at `col` itself. Past the + * end of the line there is no character, so nothing can attach there either. + */ +internal fun isPlainAsciiRun(line: TerminalLine, col: Int, bufferLimit: Int): Boolean { + for (i in col..col + 2) { + if (i >= bufferLimit) return true + if (line.charAt(i).code >= 0x80) return false + } + return true +} + /** * Terminal canvas renderer that handles all drawing operations. * Separates rendering logic from the composable for better maintainability. @@ -845,12 +891,19 @@ object TerminalCanvasRenderer { else androidx.compose.ui.text.font.FontStyle.Normal ).also { variants[variantIndex] = it } - drawTextClipped( - textMeasurer = ctx.textMeasurer, - text = batchText.toString(), - topLeft = Offset(x, y), - style = textStyle - ) + // A blank paints nothing unless the run is underlined, so a run that is + // only blanks, or that trails off into them, is asking the shaper to lay + // out invisible cells. Trim before layout; the underline below deliberately + // keeps the full width so an underlined gap still gets its rule. + val drawLength = visibleRunLength(batchText, batchIsUnderline) + if (drawLength > 0) { + drawTextClipped( + textMeasurer = ctx.textMeasurer, + text = batchText.substring(0, drawLength), + topLeft = Offset(x, y), + style = textStyle + ) + } // Draw underline for entire batch if needed if (batchIsUnderline) { @@ -924,13 +977,19 @@ object TerminalCanvasRenderer { continue } + // In a plain ASCII neighbourhood none of the three sequence probes below can + // fire, so the 20-char lookahead, the String it builds and the three scans are + // dead work - per cell, per frame, on every line of a log, a diff or source + // code. Anything non-ASCII nearby takes the original path unchanged. + val plainAscii = fastTextPath && isPlainAsciiRun(line, col, bufferLimit) + // Check for ZWJ sequences using ThreadLocal builder (issue #143 optimization) val builder = zwjCheckBuilder.get() builder.setLength(0) run { var i = col var count = 0 - while (i < bufferLimit && count < 20) { + while (!plainAscii && i < bufferLimit && count < 20) { val c = line.charAt(i) if (c != CharUtils.DWC) { builder.append(c) @@ -942,9 +1001,9 @@ object TerminalCanvasRenderer { val cleanText = builder.toString() // Use fast-path detection functions (issue #143 optimization) - val hasZWJ = GraphemeUtils.containsZWJ(cleanText) - val hasSkinTone = checkFollowingSkinTone(line, col, bufferLimit) - val hasRegionalIndicator = checkRegionalIndicatorSequence(line, col, bufferLimit) > 0 + val hasZWJ = !plainAscii && GraphemeUtils.containsZWJ(cleanText) + val hasSkinTone = !plainAscii && checkFollowingSkinTone(line, col, bufferLimit) + val hasRegionalIndicator = !plainAscii && checkRegionalIndicatorSequence(line, col, bufferLimit) > 0 if (hasZWJ || hasSkinTone || hasRegionalIndicator) { val graphemes = GraphemeUtils.segmentIntoGraphemes(cleanText) @@ -1030,17 +1089,27 @@ object TerminalCanvasRenderer { else -> true } + val isBlankCell = char == ' ' || char == '\u0000' + // The batching path appends one Char at a time. Keep surrogate // pairs on the per-character path so their low surrogate is not // dropped and rendered as U+FFFD by the text shaper. + // + // A blank draws no glyph, so only an underline makes it visible: it can extend + // a run whose underline state matches, whatever colour or weight it nominally + // carries. Letting it do so is what turns one drawText per WORD into one per + // line - aligned tables, indented source and powerline prompts are mostly + // blanks. It may not START a run, since leading blanks would shift the origin + // and shape nothing. val canBatch = analysis.lowSurrogate == null && !analysis.isDoubleWidth && !analysis.isEmojiOrWideSymbol && !analysis.isCursiveOrMath && !analysis.isTechnicalSymbol && - !isHidden && isBlinkVisible && char != ' ' && char != '\u0000' + !isHidden && isBlinkVisible && + (!isBlankCell || (fastTextPath && batchText.isNotEmpty())) val styleMatches = batchText.isNotEmpty() && - batchFgColor == fgColor && - batchIsBold == isBold && - batchIsItalic == isItalic && + (isBlankCell || batchFgColor == fgColor) && + (isBlankCell || batchIsBold == isBold) && + (isBlankCell || batchIsItalic == isItalic) && batchIsUnderline == isUnderline if (canBatch && (batchText.isEmpty() || styleMatches)) { @@ -1051,7 +1120,9 @@ object TerminalCanvasRenderer { batchIsItalic = isItalic batchIsUnderline = isUnderline } - batchText.append(char) + // NUL is a blank cell, not a glyph: appending it verbatim would hand the + // shaper a control character to draw. + batchText.append(if (isBlankCell) ' ' else char) } else { flushBatch() @@ -1609,7 +1680,7 @@ object TerminalCanvasRenderer { /** * Check if current character is followed by skin tone modifier. */ - private fun checkFollowingSkinTone(line: TerminalLine, col: Int, width: Int): Boolean { + internal fun checkFollowingSkinTone(line: TerminalLine, col: Int, width: Int): Boolean { var checkCol = col val currentChar = line.charAt(checkCol) @@ -1648,7 +1719,7 @@ object TerminalCanvasRenderer { * - [High1][Low1][DWC][High2][Low2] = 5 chars (DWC after first indicator) * - [High1][Low1][DWC][High2][Low2][DWC] = 6 chars (DWC after both) */ - private fun checkRegionalIndicatorSequence(line: TerminalLine, col: Int, width: Int): Int { + internal fun checkRegionalIndicatorSequence(line: TerminalLine, col: Int, width: Int): Int { if (col + 3 >= width) return 0 // Need at least 4 chars for 2 surrogate pairs val c1 = line.charAt(col) diff --git a/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/PlainAsciiFastPathTest.kt b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/PlainAsciiFastPathTest.kt new file mode 100644 index 000000000..877542476 --- /dev/null +++ b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/rendering/PlainAsciiFastPathTest.kt @@ -0,0 +1,138 @@ +package ai.rever.bossterm.compose.rendering + +import ai.rever.bossterm.terminal.TextStyle +import ai.rever.bossterm.terminal.model.CharBuffer +import ai.rever.bossterm.terminal.model.TerminalLine +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertFalse +import kotlin.test.assertTrue + +/** + * The ASCII fast path skips a 20-char lookahead and three sequence probes. It is only + * sound if it never skips a probe that would have fired: one false positive turns a flag, + * a family emoji or a skin-toned hand into mojibake, and none of the existing tests would + * notice because they never render. + * + * So rather than trusting the reasoning, this compares the fast path against the very + * probes it elides, over a corpus that includes every sequence kind the renderer special + * cases, at every column. + */ +class PlainAsciiFastPathTest { + + private val corpus = listOf( + "plain ascii text 0123456789 !@#\$%^&*()", + "ls -la drwxr-xr-x 12 user staff 384 Aug 26 10:11 src", + "👨‍💻 developer", // ZWJ: man technologist + "👩‍👩‍👧 fam", // ZWJ family + "flag 🇺🇸 usa", // regional indicators + "wave 👋🏽 done", // skin tone modifier + "check ✔️ mark", // variation selector + "cjk 你好 world", // wide chars + "powerline  prompt", + "a‍b", // ZWJ between ASCII + "x🏽y", // skin tone right after ASCII + ) + + @Test + fun fastPathNeverSkipsAProbeThatWouldHaveFired() { + for (text in corpus) { + val line = terminalLine(text) + val limit = line.length() + for (col in 0 until limit) { + if (!TerminalCanvasRendererTestAccess.isPlainAsciiRun(line, col, limit)) continue + + assertFalse( + TerminalCanvasRenderer.checkFollowingSkinTone(line, col, limit), + "skin tone at col $col of ${text.escaped()} would have been skipped" + ) + assertTrue( + TerminalCanvasRenderer.checkRegionalIndicatorSequence(line, col, limit) == 0, + "regional indicator at col $col of ${text.escaped()} would have been skipped" + ) + // A grapheme cluster can only pull a ZWJ into THIS cell from the very next + // one, so ASCII at col and col+1 is what rules the ZWJ branch out. + assertTrue(line.charAt(col).code < 0x80, "col $col of ${text.escaped()} is not ASCII") + if (col + 1 < limit) { + assertTrue( + line.charAt(col + 1).code < 0x80, + "col ${col + 1} of ${text.escaped()} is not ASCII" + ) + } + } + } + } + + @Test + fun fastPathStillFiresOnOrdinaryText() { + // The guard must not be so conservative that it never engages - a fast path that + // is always off would pass the test above trivially while changing nothing. + val line = terminalLine("the quick brown fox jumps over the lazy dog") + val limit = line.length() + val engaged = (0 until limit).count { + TerminalCanvasRendererTestAccess.isPlainAsciiRun(line, col = it, bufferLimit = limit) + } + assertTrue(engaged == limit, "expected the fast path at all $limit columns, got $engaged") + } + + @Test + fun fastPathDisengagesAroundNonAscii() { + val line = terminalLine("ab你cd") + val limit = line.length() + // The wide char sits at index 2, and the guard looks at col..col+2, so columns 0, + // 1 and 2 must all decline. + assertFalse(TerminalCanvasRendererTestAccess.isPlainAsciiRun(line, 0, limit)) + assertFalse(TerminalCanvasRendererTestAccess.isPlainAsciiRun(line, 1, limit)) + assertFalse(TerminalCanvasRendererTestAccess.isPlainAsciiRun(line, 2, limit)) + assertTrue(TerminalCanvasRendererTestAccess.isPlainAsciiRun(line, 3, limit)) + } + + private fun String.escaped(): String = replace(Regex("[^\\x20-\\x7E]")) { m -> + "\\u%04X".format(m.value.first().code) + } + + private fun terminalLine(text: String): TerminalLine = TerminalLine( + TerminalLine.TextEntry(TextStyle.EMPTY, CharBuffer(text)) + ) +} + +/** File-private top-level functions are not reachable from a test; this is. */ +internal object TerminalCanvasRendererTestAccess { + fun isPlainAsciiRun(line: TerminalLine, col: Int, bufferLimit: Int): Boolean = + ai.rever.bossterm.compose.rendering.isPlainAsciiRun(line, col, bufferLimit) +} + +/** + * Blanks now extend a batched run instead of breaking it, which is what collapses one + * drawText per word into one per line. The risk that buys is dropping a character that + * should have been drawn, so the trim is pinned here. + */ +class VisibleRunLengthTest { + + @Test + fun trailingBlanksAreNotShaped() { + assertEquals(3, visibleRunLength("abc ", underlined = false)) + assertEquals(0, visibleRunLength(" ", underlined = false)) + assertEquals(0, visibleRunLength("", underlined = false)) + } + + @Test + fun interiorBlanksAreKept() { + // The whole point: "a b" must stay one run of five cells, not be cut to "a". + assertEquals(5, visibleRunLength("a b", underlined = false)) + assertEquals(8, visibleRunLength("a b c", underlined = false)) + } + + @Test + fun underlinedRunsKeepTheirTrailingBlanks() { + // The blanks carry the rule, so trimming them would shorten a visible underline. + assertEquals(6, visibleRunLength("abc ", underlined = true)) + assertEquals(4, visibleRunLength(" ", underlined = true)) + } + + @Test + fun nonBlankRunsAreUntouched() { + assertEquals(3, visibleRunLength("abc", underlined = false)) + assertEquals(3, visibleRunLength("abc", underlined = true)) + } +} From 50d8eeb164c55e25c62fb2fee7fa4a282f918aa1 Mon Sep 17 00:00:00 2001 From: Shivang Date: Wed, 26 Aug 2026 20:30:46 -0700 Subject: [PATCH 03/10] docs: document the fast-text flag and the A/B ladder in the latency harness --- benchmark/latency/README.md | 22 ++++++++++++++++++++-- 1 file changed, 20 insertions(+), 2 deletions(-) diff --git a/benchmark/latency/README.md b/benchmark/latency/README.md index 69cb1ae76..3231799d8 100644 --- a/benchmark/latency/README.md +++ b/benchmark/latency/README.md @@ -67,12 +67,30 @@ same window geometry, which removes the largest source of run-to-run noise: |---|---|---| | `BOSSTERM_REDRAW_DEBOUNCE_MS` | unset (8 ms) | `0` | | `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS` | unset (50 ms) | `0` | +| `BOSSTERM_FAST_TEXT` | unset | `1` | | `performanceMode` in `~/.bossterm/settings.json` | `balanced` | `latency` | -The two env vars are measurement scaffolding and are removed once the debounce question is -settled. With neither set, the build behaves exactly as shipped, so a run with no env is a +`BOSSTERM_FAST_TEXT` turns on the renderer reductions: ASCII cells skip the grapheme +sequence probes, and blanks extend a batched run instead of flushing it (one `drawText` per +line rather than per word). Watch `drawCallsPerFrame` and `paintCostMs` for its effect; +`byteToPaintMs` should follow only if paint cost was actually on the critical path. + +All three env vars are measurement scaffolding and come out once the questions they answer +are settled. With none set, the build behaves exactly as shipped, so a run with no env is a true baseline. +Suggested ladder, one workload at a time, resetting between each: + +1. nothing set - baseline +2. `performanceMode=latency` - removes the 5 ms data-stream poll +3. `+ BOSSTERM_REDRAW_DEBOUNCE_MS=0` - removes the 8 ms interactive debounce +4. `+ BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS=0` - removes the 50 ms bulk-output throttle +5. `+ BOSSTERM_FAST_TEXT=1` - renderer reductions + +Step 4 is the one to watch for regressions rather than gains: if paint cost is still high, +removing the throttle can cost throughput without buying latency. That is the measurement +that decides whether the renderer work in step 5 is a prerequisite or an optimisation. + ## External anchor - do this once The in-process number is a proxy. Before any conclusion rests on it, confirm it tracks From 4b2ff5d489ab9ff174ccd1ffb99652a2e9e1ba79 Mon Sep 17 00:00:00 2001 From: Shivang Date: Wed, 26 Aug 2026 22:09:02 -0700 Subject: [PATCH 04/10] perf: split the probe at the redraw trigger, and record the measured baseline byteToPaint alone cannot say WHERE the time goes, and a slow recomposition and a long debounce have opposite fixes. triggerToPaintMs splits it: everything up to actualRedraw (queue wait, parse, debounce) versus everything after it (recompose, layout, draw). That split is what made the results readable, and it disproved a hypothesis I had been carrying: recomposition of the 2400-line ProperTerminal is NOT a bottleneck. triggerToPaint is 1.8-13.3 ms and tracks paint cost. Measured baseline in benchmark_results/LATENCY_BASELINE_2026-08-27.md. Headlines: 1. An occluded window is throttled to ~3 fps by macOS, and Compose's frame clock follows. Same tui workload, same process: 29 paints and 295 ms p50 covered, 653 paints and 9.2 ms p50 raised. That is ~30x larger than anything being measured, so it silently makes a healthy build look catastrophic. Every run now asserts the window is frontmost before starting. 2. The debounce, not the renderer, owns the multi-second lag on bulk output. bulk p95: 1310 ms baseline, 1704 ms with the renderer reductions on and the debounce untouched, 10.2 ms with the debounce zeroed. Renderer work alone does not help; zeroing the debounce collapses the tail by ~99%. 3. Blank batching cuts drawText calls 208 -> 28 per frame on tui, but paint cost only 11.3 -> 9.2 ms. So draw-call COUNT was not the dominant paint cost. That argues against the next renderer step as scoped: caching TextLayoutResult, or a Skia TextBlob fast path, both attack the same ~19% slice that run-merging just showed is small. Per-cell work in the two full-grid passes is the bigger target. 4. The O(scrollback) snapshot is real but small: lockedCapture p50 rises 0.03 -> 1.28 ms with 10k lines of history, ~40x, but that is ~8% of a frame. Worth fixing, not worth prioritising. The interactive path came out where reading the code predicted: 16.4 ms baseline, of which only 1.8 ms is after the trigger, so ~14.6 ms is the 5 ms poll plus the 8 ms debounce plus parse. --- .../LATENCY_BASELINE_2026-08-27.md | 112 ++++++++++++++++++ .../compose/ComposeTerminalDisplay.kt | 2 + .../compose/rendering/FrameLatencyProbe.kt | 24 ++++ 3 files changed, 138 insertions(+) create mode 100644 benchmark_results/LATENCY_BASELINE_2026-08-27.md diff --git a/benchmark_results/LATENCY_BASELINE_2026-08-27.md b/benchmark_results/LATENCY_BASELINE_2026-08-27.md new file mode 100644 index 000000000..35aed7fd9 --- /dev/null +++ b/benchmark_results/LATENCY_BASELINE_2026-08-27.md @@ -0,0 +1,112 @@ +# Glass-to-pixel latency baseline + +**Date:** 2026-08-27 +**Base:** `perf/terminal-latency` @ 736b646b, off `origin/master` @ cacaba54 +**Platform:** macOS (Darwin 25.5.0, Apple Silicon), Compose Multiplatform 1.9.3 +**Method:** `FrameLatencyProbe` + `benchmark/latency/workloads.sh`, one process per config, +probe reset and scrollback wiped before each workload. All figures are milliseconds. + +Latencies are measured to **draw-issued**, excluding GPU present and vsync, so they are a +lower bound. Comparisons between configs are sound; absolute values still need the external +camera anchor described in `benchmark/latency/README.md`. + +--- + +## Finding 0: an occluded window is throttled to ~3 fps, and that swamps everything + +Same workload, same process, only window visibility differing: + +| `tui` | paints | byteToPaint p50 | triggerToPaint p50 | +|---|---|---|---| +| occluded behind another window | 29 | 294.9 | 294.9 | +| raised and focused | 653 | **9.2** | 13.3 | + +macOS throttles a covered window and Compose's frame clock follows it down. This is not a +BossTerm defect, but it is a measurement trap: it is ~30x larger than any effect being +measured, and it silently makes a healthy build look catastrophic. **Every measurement in +this document was taken with the window raised**, verified per run by asserting the +frontmost process before the workload starts. + +An earlier draft of this file reported 262-917 ms figures that were entirely this artefact. + +--- + +## Results + +| workload | config | byteToPaint p50 | p95 | paintCost p50 | drawCalls p50 | +|---|---|---|---|---|---| +| interactive | baseline | 16.4 | 18.4 | 1.15 | 11 | +| interactive | fast-text only | 20.5 | 24.6 | 1.79 | 10 | +| interactive | debounce 0 + fast-text | **10.2** | 14.3 | 3.07 | 10 | +| bulk | baseline | 81.9 | **1310.7** | 1.41 | 20 | +| bulk | fast-text only | 589.8 | **1703.9** | 2.56 | 56 | +| bulk | debounce 0 + fast-text | **9.2** | **10.2** | 1.92 | 15 | +| tui | baseline | 9.2 | 15.4 | 11.26 | **208** | +| tui | fast-text only | 8.2 | 15.4 | 9.22 | **28** | +| tui | debounce 0 + fast-text | 10.2 | 12.3 | 9.22 | 28 | +| scroll | baseline | 41.0 | 73.7 | 5.63 | 176 | +| scroll | debounce 0 + fast-text | 32.8 | 73.7 | **1.66** | 56 | + +--- + +## What the numbers say + +**1. The interactive echo path costs what the constants said it would.** +Baseline `interactive` is 16.4 ms, of which only 1.8 ms is `triggerToPaint`. So ~14.6 ms is +spent before the redraw trigger: the 5 ms `BALANCED` poll plus the 8 ms debounce plus parse. +That is the ~13 ms predicted from reading the code, confirmed independently. Setting +`BOSSTERM_REDRAW_DEBOUNCE_MS=0` recovers 6 ms of it. + +**2. The debounce, not the renderer, owns the multi-second lag on bulk output.** +This is the largest single effect found: + +| bulk p95 | | +|---|---| +| baseline | 1310.7 | +| fast-text only, debounce untouched | 1703.9 | +| debounce 0 | **10.2** | + +Turning the renderer reductions on while leaving the debounce alone does **not** help - the +tail stays above a second. Zeroing the debounce collapses it by ~99%. `triggerToPaint` p95 +stays at 12-18 ms throughout, so the time is all upstream of the trigger: output piles up +behind `HIGH_VOLUME`'s 50 ms sleep once the rate detector trips, and the queue never drains +while the workload runs. + +**3. Blank batching cuts draw calls ~7x, but paint cost only ~19%.** +On `tui`, where frame content is comparable across configs, `drawCallsPerFrame` p50 goes +208 -> 28 while `paintCost` p50 goes 11.26 -> 9.22. So the number of `drawText` calls was +**not** the dominant paint cost. Whatever remains is per-cell work in the two full-grid +passes, not per-run text layout. + +This is the most consequential result for planning, because it argues **against** the +next renderer step as originally scoped: caching `TextLayoutResult`, or dropping to a Skia +`TextBlob` fast path, both attack the same ~19% slice that run-merging just showed is small. +The per-cell scan and colour-conversion work in `renderBackgrounds` / `renderText` is the +bigger target. + +**4. Recomposition is not a bottleneck.** +`triggerToPaint` - the window covering recomposition, layout and draw - is 1.8-13.3 ms and +tracks `paintCost` closely. The 2400-line `ProperTerminal` recomposing per frame was +suspected as a major cost; it is not. + +**5. The O(scrollback) snapshot is real but small.** +`lockedCaptureMs` p50 rises from 0.03 ms on a fresh buffer to 1.28 ms with 10 000 lines of +history (`aged`), ~40x, confirming the per-frame walk over screen plus full history. But +1.3 ms of a 16.7 ms frame is ~8%, not the reason long sessions feel worse. Worth fixing, +not worth prioritising. + +--- + +## Reproducing + +```bash +BOSSTERM_FRAME_PROBE=1 ./gradlew :bossterm-app:run --no-daemon +# raise the window, then per workload: +./benchmark/latency/probe.sh reset +./benchmark/latency/workloads.sh +./benchmark/latency/probe.sh show +``` + +Add `BOSSTERM_REDRAW_DEBOUNCE_MS=0`, `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS=0` and +`BOSSTERM_FAST_TEXT=1` to the launch for the other configs. **Raise the window before each +run** or finding 0 will dominate the result. diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt index d01ef2520..c689adff0 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt @@ -1,5 +1,6 @@ package ai.rever.bossterm.compose +import ai.rever.bossterm.compose.rendering.FrameLatencyProbe import androidx.compose.runtime.mutableStateOf import androidx.compose.runtime.State import ai.rever.bossterm.core.util.TermSize @@ -604,6 +605,7 @@ class ComposeTerminalDisplay : TerminalDisplay { * Perform the actual redraw by updating Compose state. */ private fun actualRedraw() { + FrameLatencyProbe.markRedrawTriggered() _redrawTrigger.value += 1 } diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt index 1a7089e63..ed8209b53 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt @@ -63,10 +63,23 @@ object FrameLatencyProbe { */ private val pendingArrival = AtomicLong(NONE) + /** Oldest redraw trigger not yet painted, or [NONE]. Same earliest-wins rule as arrival. */ + private val pendingTrigger = AtomicLong(NONE) + /** Reset per paint by [beginFrame], read by [endFrame]. */ private val drawCalls = AtomicInteger(0) val byteToPaint: Histogram = Histogram() + + /** + * Redraw trigger to paint: the recomposition and layout window. + * + * [byteToPaint] alone cannot say WHERE the time goes. This splits it: everything up to + * `actualRedraw` (queue wait, parse, debounce) versus everything after it (recomposing + * the composable, layout, then the draw). Without the split, a slow recomposition and a + * long debounce are indistinguishable, and they have opposite fixes. + */ + val triggerToPaint: Histogram = Histogram() val paintCost: Histogram = Histogram() val snapshotCost: Histogram = Histogram() val drawCallsPerFrame: Histogram = Histogram() @@ -136,6 +149,7 @@ object FrameLatencyProbe { .append(String.format(java.util.Locale.ROOT, "%.1f", (System.nanoTime() - startedAtNanos) / 1e9)) .append(",\n") append(" \"byteToPaintMs\": ").append(byteToPaint.jsonMillis()).append(",\n") + append(" \"triggerToPaintMs\": ").append(triggerToPaint.jsonMillis()).append(",\n") append(" \"paintCostMs\": ").append(paintCost.jsonMillis()).append(",\n") append(" \"lockedCaptureMs\": ").append(snapshotCost.jsonMillis()).append(",\n") append(" \"drawCallsPerFrame\": ").append(drawCallsPerFrame.jsonRaw()).append(",\n") @@ -159,6 +173,12 @@ object FrameLatencyProbe { /** Timestamp for a later `record*` call, or 0 when the probe is off. */ fun startTiming(): Long = if (enabled) System.nanoTime() else 0L + /** `actualRedraw` bumped the Compose state that will cause the next recomposition. */ + fun markRedrawTriggered() { + if (!enabled) return + pendingTrigger.compareAndSet(NONE, System.nanoTime()) + } + /** Start of a paint pass. Returns the start timestamp to hand back to [endFrame]. */ fun beginFrame(): Long { if (!enabled) return 0L @@ -172,6 +192,8 @@ object FrameLatencyProbe { val now = System.nanoTime() paintCost.recordNanos(now - startNanos) drawCallsPerFrame.record(drawCalls.get().toLong()) + val trigger = pendingTrigger.getAndSet(NONE) + if (trigger != NONE) triggerToPaint.recordNanos(now - trigger) val arrival = pendingArrival.getAndSet(NONE) if (arrival == NONE) idleFrames.incrementAndGet() else byteToPaint.recordNanos(now - arrival) } @@ -196,11 +218,13 @@ object FrameLatencyProbe { /** Drop every sample. Call between workloads so runs do not contaminate each other. */ fun reset() { byteToPaint.reset() + triggerToPaint.reset() paintCost.reset() snapshotCost.reset() drawCallsPerFrame.reset() idleFrames.set(0) pendingArrival.set(NONE) + pendingTrigger.set(NONE) drawCalls.set(0) } From e8e04afb19656cf380b763befd386310be56ef9d Mon Sep 17 00:00:00 2001 From: Shivang Date: Wed, 26 Aug 2026 22:26:51 -0700 Subject: [PATCH 05/10] perf: remove the redraw debounce and default performanceMode to latency Interactive echo goes from 16.4 ms to ~2.0 ms, an 87% cut, measured over three consecutive runs (1.9 / 2.3 / 2.0 p50). Afterwards byteToPaint equals triggerToPaint, which is the signature of nothing being spent ahead of the redraw trigger - the 8 ms debounce and the 5 ms BALANCED poll were the whole gap. Frame counts stay vsync-capped (~62/sec) without the debounce, so the sleep was never what kept the terminal from over-rendering: the frame clock was, and the CONFLATED channel plus Compose's per-frame coalescing already do the job it was added for. With the wait gone, the adaptive machinery around it had no purpose left, so it goes too: RedrawMode, RedrawPriority, the redraws/sec detector, the mode-transition job, and the 100 ms mode-reset coroutine that requestImmediateRedraw launched on every keystroke. scrollArea had been branching on the mode to pick between the conflated and non-conflated path; with both paths now identical in timing it takes the conflated one. Net -131 lines. CORRECTION to the previous commit's claim. It said zeroing the debounce took bulk p95 from 1310 ms to 10.2 ms, a ~99% collapse. That was wrong: it rested on a single run that returned only 33 samples, which should have been treated as suspect rather than reported. Three consecutive runs on these defaults give p95 983.0 ms every time. The real bulk improvement is ~25%, not a fix. The split probe says exactly where the rest goes: on bulk, triggerToPaint p50 is 6.7 ms against a byteToPaint p50 of 491.5 ms, so ~485 ms is upstream of the trigger. With the debounce gone that is queue wait and parse - a 5 MB cat arrives as ~640 chunks through an 8 KiB read buffer, each allocating a ByteArray, a copyOf and a String, into an emulator that pulls them back one Char at a time. Bulk output is a PTY-path problem, not a render-path one, and is not addressed here. benchmark_results/LATENCY_BASELINE_2026-08-27.md rewritten with the corrected numbers and the three-run medians. --- .../LATENCY_BASELINE_2026-08-27.md | 144 +++++++------ .../compose/ComposeTerminalDisplay.kt | 200 +++--------------- .../compose/settings/TerminalSettings.kt | 18 +- 3 files changed, 122 insertions(+), 240 deletions(-) diff --git a/benchmark_results/LATENCY_BASELINE_2026-08-27.md b/benchmark_results/LATENCY_BASELINE_2026-08-27.md index 35aed7fd9..b4cac1247 100644 --- a/benchmark_results/LATENCY_BASELINE_2026-08-27.md +++ b/benchmark_results/LATENCY_BASELINE_2026-08-27.md @@ -1,13 +1,13 @@ -# Glass-to-pixel latency baseline +# Glass-to-pixel latency: baseline and the debounce removal **Date:** 2026-08-27 -**Base:** `perf/terminal-latency` @ 736b646b, off `origin/master` @ cacaba54 +**Base:** `perf/terminal-latency`, off `origin/master` @ cacaba54 **Platform:** macOS (Darwin 25.5.0, Apple Silicon), Compose Multiplatform 1.9.3 **Method:** `FrameLatencyProbe` + `benchmark/latency/workloads.sh`, one process per config, -probe reset and scrollback wiped before each workload. All figures are milliseconds. +probe reset and scrollback wiped before each workload. Figures are milliseconds. Latencies are measured to **draw-issued**, excluding GPU present and vsync, so they are a -lower bound. Comparisons between configs are sound; absolute values still need the external +lower bound. Comparisons between configs are sound; absolute values still want the external camera anchor described in `benchmark/latency/README.md`. --- @@ -18,16 +18,14 @@ Same workload, same process, only window visibility differing: | `tui` | paints | byteToPaint p50 | triggerToPaint p50 | |---|---|---|---| -| occluded behind another window | 29 | 294.9 | 294.9 | +| covered by another window | 29 | 294.9 | 294.9 | | raised and focused | 653 | **9.2** | 13.3 | -macOS throttles a covered window and Compose's frame clock follows it down. This is not a -BossTerm defect, but it is a measurement trap: it is ~30x larger than any effect being -measured, and it silently makes a healthy build look catastrophic. **Every measurement in -this document was taken with the window raised**, verified per run by asserting the -frontmost process before the workload starts. - -An earlier draft of this file reported 262-917 ms figures that were entirely this artefact. +macOS throttles a covered window and Compose's frame clock follows it down. Not a BossTerm +defect, but a measurement trap: it is ~30x larger than any effect being measured, so it does +not look like noise, it looks like a catastrophic product bug. **Every figure below was taken +with the window raised**, asserted per run before the workload starts. An earlier draft of +this file reported 262-917 ms numbers that were entirely this artefact. --- @@ -35,65 +33,74 @@ An earlier draft of this file reported 262-917 ms figures that were entirely thi | workload | config | byteToPaint p50 | p95 | paintCost p50 | drawCalls p50 | |---|---|---|---|---|---| -| interactive | baseline | 16.4 | 18.4 | 1.15 | 11 | -| interactive | fast-text only | 20.5 | 24.6 | 1.79 | 10 | -| interactive | debounce 0 + fast-text | **10.2** | 14.3 | 3.07 | 10 | -| bulk | baseline | 81.9 | **1310.7** | 1.41 | 20 | -| bulk | fast-text only | 589.8 | **1703.9** | 2.56 | 56 | -| bulk | debounce 0 + fast-text | **9.2** | **10.2** | 1.92 | 15 | -| tui | baseline | 9.2 | 15.4 | 11.26 | **208** | +| interactive | baseline (balanced, 8/50 ms debounce) | 16.4 | 18.4 | 1.15 | 11 | +| interactive | latency mode only | 12.3 | 14.3 | 1.54 | - | +| interactive | **shipped defaults (debounce removed + latency)** | **1.9 - 2.3** | 2.6 - 3.1 | 1.92 | 11 | +| bulk | baseline | 81.9 | 1310.7 | 1.41 | 20 | +| bulk | latency mode only | 196.6 | 1441.8 | 2.56 | - | +| bulk | **shipped defaults** | 491.5 | **983.0** | 4.10 | 128 | +| tui | baseline | 9.2 | 15.4 | 11.26 | 208 | | tui | fast-text only | 8.2 | 15.4 | 9.22 | **28** | -| tui | debounce 0 + fast-text | 10.2 | 12.3 | 9.22 | 28 | +| tui | shipped defaults | 13.3 | 15.4 | 12.29 | 208 | | scroll | baseline | 41.0 | 73.7 | 5.63 | 176 | -| scroll | debounce 0 + fast-text | 32.8 | 73.7 | **1.66** | 56 | +| scroll | shipped defaults | 20.5 | 65.5 | 4.61 | 176 | + +The `interactive` and `bulk` "shipped defaults" rows are the median of three consecutive +runs each; they were tight (interactive p50 1.9/2.3/2.0, bulk p95 983.0 three times). --- -## What the numbers say - -**1. The interactive echo path costs what the constants said it would.** -Baseline `interactive` is 16.4 ms, of which only 1.8 ms is `triggerToPaint`. So ~14.6 ms is -spent before the redraw trigger: the 5 ms `BALANCED` poll plus the 8 ms debounce plus parse. -That is the ~13 ms predicted from reading the code, confirmed independently. Setting -`BOSSTERM_REDRAW_DEBOUNCE_MS=0` recovers 6 ms of it. - -**2. The debounce, not the renderer, owns the multi-second lag on bulk output.** -This is the largest single effect found: - -| bulk p95 | | -|---|---| -| baseline | 1310.7 | -| fast-text only, debounce untouched | 1703.9 | -| debounce 0 | **10.2** | - -Turning the renderer reductions on while leaving the debounce alone does **not** help - the -tail stays above a second. Zeroing the debounce collapses it by ~99%. `triggerToPaint` p95 -stays at 12-18 ms throughout, so the time is all upstream of the trigger: output piles up -behind `HIGH_VOLUME`'s 50 ms sleep once the rate detector trips, and the queue never drains -while the workload runs. - -**3. Blank batching cuts draw calls ~7x, but paint cost only ~19%.** -On `tui`, where frame content is comparable across configs, `drawCallsPerFrame` p50 goes -208 -> 28 while `paintCost` p50 goes 11.26 -> 9.22. So the number of `drawText` calls was -**not** the dominant paint cost. Whatever remains is per-cell work in the two full-grid -passes, not per-run text layout. - -This is the most consequential result for planning, because it argues **against** the -next renderer step as originally scoped: caching `TextLayoutResult`, or dropping to a Skia -`TextBlob` fast path, both attack the same ~19% slice that run-merging just showed is small. -The per-cell scan and colour-conversion work in `renderBackgrounds` / `renderText` is the -bigger target. - -**4. Recomposition is not a bottleneck.** -`triggerToPaint` - the window covering recomposition, layout and draw - is 1.8-13.3 ms and -tracks `paintCost` closely. The 2400-line `ProperTerminal` recomposing per frame was -suspected as a major cost; it is not. - -**5. The O(scrollback) snapshot is real but small.** -`lockedCaptureMs` p50 rises from 0.03 ms on a fresh buffer to 1.28 ms with 10 000 lines of -history (`aged`), ~40x, confirming the per-frame walk over screen plus full history. But -1.3 ms of a 16.7 ms frame is ~8%, not the reason long sessions feel worse. Worth fixing, -not worth prioritising. +## What shipped, and what it bought + +**The interactive echo path: 16.4 ms -> ~2.0 ms, an 87% cut.** +Baseline `interactive` was 16.4 ms of which only 1.8 ms was `triggerToPaint`, so ~14.6 ms sat +ahead of the redraw trigger: the 5 ms `BALANCED` poll, the 8 ms debounce, and parse. Removing +both leaves `byteToPaint` essentially equal to `triggerToPaint` (1.9 vs 1.8), which is the +signature of nothing being spent before the trigger. This is the path a user feels while +typing, and it is now bounded by the frame clock rather than by a sleep. + +**Frame counts stayed vsync-capped without the debounce** (~62/sec on `tui`), so the sleep was +not what kept the terminal from over-rendering: the frame clock was, and the CONFLATED +channel plus Compose's own per-frame coalescing already do the job the debounce was added for. + +--- + +## Correction: the debounce does NOT own the bulk-output tail + +An earlier revision of this file claimed removing the debounce took `bulk` p95 from 1310 ms to +10.2 ms, a ~99% collapse. **That was wrong.** It rested on a single run that returned only 33 +samples, which should have been treated as suspect rather than reported. Three consecutive +runs on the shipped defaults give p95 983.0 ms every time. + +The honest result is a ~25% improvement on the bulk tail (1310 -> 983 ms), not a fix. + +Where the remaining second goes is now unambiguous, because the probe is split at the redraw +trigger: on `bulk`, `triggerToPaint` p50 is 6.7 ms while `byteToPaint` p50 is 491.5 ms. So +~485 ms of it is upstream of the trigger, and with the debounce gone that leaves **queue wait +and parse**. A 5 MB `cat` arrives as ~640 chunks through an 8 KiB read buffer +(`PlatformServices.desktop.kt`), each one allocating a `ByteArray`, a `copyOf`, and a +`String`, before an emulator that pulls them back out one `Char` at a time. + +**So the bulk-output fix is the PTY and parse path, not the renderer and not the debounce.** +That is a different piece of work from anything on this branch. + +--- + +## Also measured, and worth knowing before scoping renderer work + +**Draw-call count is not the dominant paint cost.** Blank batching (`BOSSTERM_FAST_TEXT=1`) +cut `drawText` calls 208 -> 28 per frame on `tui`, an 86% reduction, while `paintCost` moved +only 11.26 -> 9.22 ms, 19%. Caching `TextLayoutResult`, or dropping to a Skia `TextBlob` fast +path, both attack that same 19% slice. The per-cell scan and colour-conversion work in the two +full-grid passes is the bigger target. + +**Recomposition is not a bottleneck.** `triggerToPaint` covers recomposition, layout and draw; +it is 1.8-13.3 ms and tracks `paintCost` closely. The 2400-line `ProperTerminal` recomposing +per frame had been suspected as a major cost. It is not. + +**The O(scrollback) snapshot is real but small.** `lockedCapture` p50 rises 0.03 -> 1.28 ms +with 10 000 lines of history (`aged`), roughly 40x, confirming the per-frame walk over screen +plus full history. But 1.3 ms of a 16.7 ms frame is ~8%: worth fixing, not worth prioritising. --- @@ -107,6 +114,5 @@ BOSSTERM_FRAME_PROBE=1 ./gradlew :bossterm-app:run --no-daemon ./benchmark/latency/probe.sh show ``` -Add `BOSSTERM_REDRAW_DEBOUNCE_MS=0`, `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS=0` and -`BOSSTERM_FAST_TEXT=1` to the launch for the other configs. **Raise the window before each -run** or finding 0 will dominate the result. +`BOSSTERM_FAST_TEXT=1` enables the renderer reductions, which remain opt-in. **Raise the +window before every run** or finding 0 will dominate the result. diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt index c689adff0..71da1522a 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt @@ -18,61 +18,39 @@ import kotlinx.coroutines.flow.asStateFlow import java.util.concurrent.atomic.AtomicReference /** - * Compose implementation of TerminalDisplay interface with adaptive debouncing. + * Compose implementation of TerminalDisplay. * - * Phase 2 Optimization: Automatically switches between three rendering modes - * based on output rate to reduce redraws by 51-91% for medium/large files - * while maintaining zero latency for interactive use. + * Redraws are coalesced by the CONFLATED [redrawChannel] and, downstream of it, by Compose + * itself: many writes to [_redrawTrigger] between two frames collapse into one + * recomposition. Nothing here waits on a clock. + * + * It used to. An adaptive debounce slept 8 ms per redraw, and 50 ms once output passed 100 + * redraws/sec, to cut redraw COUNT on large files. Measured against the thing a user + * actually feels, that trade was bad: an isolated keystroke echo took 16.4 ms, of which only + * 1.8 ms was downstream of the redraw trigger. Removing the wait (with the data stream's own + * poll, see TerminalSettings.performanceMode) takes it to ~2.0 ms, and `byteToPaint` then + * equals `triggerToPaint`, which is the signature of nothing being spent before the trigger. + * + * Frame counts stay vsync-capped (~62/sec) without it, so the sleep was never what kept the + * terminal from over-rendering: the frame clock was, and the CONFLATED channel plus Compose's + * per-frame coalescing already do the job this was added for. + * + * What it does NOT fix is bulk output: a 5 MB `cat` still shows a ~983 ms p95, down only + * ~25% from 1310 ms, and on that workload `triggerToPaint` is 6.7 ms against a `byteToPaint` + * of 491 ms. That ~485 ms is queue wait and parse, upstream of anything here. + * + * See `benchmark_results/LATENCY_BASELINE_2026-08-27.md`. */ -private val interactiveDebounceOverrideMs: Long? = - System.getenv("BOSSTERM_REDRAW_DEBOUNCE_MS")?.toLongOrNull()?.coerceAtLeast(0L) - -private val highVolumeDebounceOverrideMs: Long? = - System.getenv("BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS")?.toLongOrNull()?.coerceAtLeast(0L) - class ComposeTerminalDisplay : TerminalDisplay { - // ===== ADAPTIVE DEBOUNCING (Phase 2) ===== - - /** - * Rendering modes that adapt to output rate. - */ - enum class RedrawMode(val debounceMs: Long, val description: String) { - INTERACTIVE(8L, "120fps equivalent for responsive typing"), - HIGH_VOLUME(50L, "20fps for bulk output, triggered at >100 redraws/sec"), - IMMEDIATE(0L, "Instant for keyboard/mouse input") - } /** - * Effective debounce for [mode], with a measurement-time override. - * - * MEASUREMENT SCAFFOLDING - to be removed once the debounce question is settled. - * `BOSSTERM_REDRAW_DEBOUNCE_MS` and `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS` let a single - * build A/B the wait without a rebuild-and-relaunch between every sample, which is the - * only way to compare two configurations against the same warmed JIT, the same window - * size and the same shell history. Unset, both fall through to the shipped constants, - * so a run with no env set is a true baseline. - * - * `delay(0)` returns without suspending, so an override of 0 costs no dispatch hop. - */ - private fun debounceMsFor(mode: RedrawMode): Long = when (mode) { - RedrawMode.INTERACTIVE -> interactiveDebounceOverrideMs ?: mode.debounceMs - RedrawMode.HIGH_VOLUME -> highVolumeDebounceOverrideMs ?: mode.debounceMs - RedrawMode.IMMEDIATE -> mode.debounceMs - } - - /** - * Redraw request with priority. + * Redraw request. Carries no priority any more: with the debounce gone, an "immediate" + * and a "normal" request do exactly the same thing. */ data class RedrawRequest( val timestamp: Long = System.currentTimeMillis(), - val priority: RedrawPriority = RedrawPriority.NORMAL ) - enum class RedrawPriority { - IMMEDIATE, // User input - bypass debounce - NORMAL // PTY output - apply debounce - } - /** * The four cursor fields as ONE value. * @@ -88,24 +66,12 @@ class ComposeTerminalDisplay : TerminalDisplay { val shape: CursorShape?, ) - // Current rendering mode - @Volatile - private var currentMode = RedrawMode.INTERACTIVE - // Channel for queuing redraw requests with conflation private val redrawChannel = Channel(Channel.CONFLATED) // Coroutine scope for redraw processing private val redrawScope = CoroutineScope(Dispatchers.Main + SupervisorJob()) - // Timestamp tracking for burst detection - private val recentRedraws = ArrayDeque(100) - private val redrawTimestampsLock = Any() - - // Mode transition tracking - private var lastModeSwitch = System.currentTimeMillis() - private var returnToInteractiveJob: Job? = null - init { // Start redraw processor coroutine startRedrawProcessor() @@ -274,18 +240,7 @@ class ComposeTerminalDisplay : TerminalDisplay { override fun scrollArea(scrollRegionTop: Int, scrollRegionSize: Int, dy: Int) { // Note: This method is only called for actual scrolling operations (cursor past bottom, etc.) // Regular text output is handled by the ModelListener registered on TerminalTextBuffer - // Smart priority detection: Use IMMEDIATE for interactive use, NORMAL for bulk output - val isHighVolume = synchronized(redrawTimestampsLock) { - currentMode == RedrawMode.HIGH_VOLUME - } - - if (isHighVolume) { - // Bulk output detected (cat, streaming) - use debouncing for 98% reduction - requestRedraw() - } else { - // Interactive use (typing, prompts) - instant response for best UX - requestImmediateRedraw() - } + requestRedraw() } override fun useAlternateScreenBuffer(useAlternateScreenBuffer: Boolean) { @@ -366,35 +321,16 @@ class ComposeTerminalDisplay : TerminalDisplay { try { for (request in redrawChannel) { try { - when (request.priority) { - RedrawPriority.IMMEDIATE -> { - // Re-check sync mode: a ?2026h may have arrived after this - // redraw was queued (e.g., rapid ?2026l/?2026h toggle by CLIs - // like "claude" that use synchronized output for spinner frames). - synchronized(syncUpdateLock) { - if (_synchronizedUpdateEnabled) { - _pendingRedrawDuringSync = true - null - } else Unit - } ?: continue - actualRedraw() - } - - RedrawPriority.NORMAL -> { - val mode = detectAndUpdateMode() - delay(debounceMsFor(mode)) - - // Re-check sync mode after debounce delay: a new ?2026h may - // have been processed by the emulator while we were waiting. - synchronized(syncUpdateLock) { - if (_synchronizedUpdateEnabled) { - _pendingRedrawDuringSync = true - null - } else Unit - } ?: continue - actualRedraw() - } - } + // Re-check sync mode: a ?2026h may have arrived after this + // redraw was queued (e.g., rapid ?2026l/?2026h toggle by CLIs + // like "claude" that use synchronized output for spinner frames). + synchronized(syncUpdateLock) { + if (_synchronizedUpdateEnabled) { + _pendingRedrawDuringSync = true + null + } else Unit + } ?: continue + actualRedraw() } catch (e: Exception) { // Log but don't crash the loop - individual redraw failures // should not kill the entire rendering pipeline @@ -416,61 +352,6 @@ class ComposeTerminalDisplay : TerminalDisplay { } } - /** - * Detect current redraw rate and update mode accordingly. - * Switches to HIGH_VOLUME when >100 redraws/sec detected. - */ - private fun detectAndUpdateMode(): RedrawMode { - val now = System.currentTimeMillis() - - synchronized(redrawTimestampsLock) { - // Add current timestamp - recentRedraws.addLast(now) - - // Remove timestamps older than 1 second - while (recentRedraws.isNotEmpty() && - now - recentRedraws.first() > 1000) { - recentRedraws.removeFirst() - } - - // Calculate redraws per second - val rate = recentRedraws.size - - // Determine appropriate mode - val newMode = when { - rate > 100 -> RedrawMode.HIGH_VOLUME // Bulk output detected - else -> RedrawMode.INTERACTIVE // Normal interactive use - } - - // Handle mode transition - if (newMode != currentMode && newMode != RedrawMode.IMMEDIATE) { - onModeTransition(currentMode, newMode) - currentMode = newMode - lastModeSwitch = now - } - - return currentMode - } - } - - /** - * Handle transitions between rendering modes. - */ - private fun onModeTransition(from: RedrawMode, to: RedrawMode) { - // Schedule automatic return to INTERACTIVE after bulk output stops - if (to == RedrawMode.HIGH_VOLUME) { - returnToInteractiveJob?.cancel() - returnToInteractiveJob = redrawScope.launch { - delay(500) // Wait 500ms of low activity - synchronized(redrawTimestampsLock) { - if (recentRedraws.size < 50) { // Less than 50 redraws/sec - currentMode = RedrawMode.INTERACTIVE - } - } - } - } - } - /** * Trigger a redraw of the terminal (normal priority, applies debouncing). */ @@ -486,7 +367,7 @@ class ComposeTerminalDisplay : TerminalDisplay { // Conflated channel: a full channel simply coalesces this request into the // pending one, which is the intended debouncing behaviour. - redrawChannel.trySend(RedrawRequest(priority = RedrawPriority.NORMAL)) + redrawChannel.trySend(RedrawRequest()) } /** @@ -589,16 +470,6 @@ class ComposeTerminalDisplay : TerminalDisplay { } actualRedraw() } - - // Reset to INTERACTIVE mode after brief delay - redrawScope.launch { - delay(100) - synchronized(redrawTimestampsLock) { - if (currentMode != RedrawMode.HIGH_VOLUME) { - currentMode = RedrawMode.INTERACTIVE - } - } - } } /** @@ -620,7 +491,6 @@ class ComposeTerminalDisplay : TerminalDisplay { * and closing an already-closed channel are both no-ops. */ fun dispose() { - returnToInteractiveJob?.cancel() redrawJob?.cancel() redrawScope.cancel() redrawChannel.close() diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/settings/TerminalSettings.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/settings/TerminalSettings.kt index 26d50b3cf..645d4f7fd 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/settings/TerminalSettings.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/settings/TerminalSettings.kt @@ -620,14 +620,20 @@ data class TerminalSettings( /** * Performance optimization mode. - * - "latency": Optimized for interactive responsiveness (faster command response, lower throughput) - * - "throughput": Optimized for bulk output (higher throughput, slightly higher latency) - * - "balanced": Balance between latency and throughput (default) + * - "latency" (default): the data stream never waits for more bytes than it already has + * - "throughput": waits up to 10 ms on buffer exhaustion to batch more aggressively + * - "balanced": waits up to 5 ms * - * Use "latency" for: SSH sessions, interactive commands, shell usage - * Use "throughput" for: Large file operations, build logs, data processing + * The wait happens in `readNonControlCharacters` with the printable characters already + * in hand, so on an interactive echo it is pure added latency. Measured: switching the + * default from "balanced" to "latency" took byte-to-pixel p50 from 16.4 ms to 12.3 ms + * with nothing else changed (`benchmark_results/LATENCY_BASELINE_2026-08-27.md`). The + * throughput this was trading for is not visible at 8 KB chunk sizes. + * + * Use "throughput" only for a session that is genuinely bulk-output bound and whose + * latency nobody is watching. */ - val performanceMode: String = "balanced", + val performanceMode: String = "latency", /** * Maximum refresh rate in FPS (0 = unlimited) From 195ed04e3919fd4a87cf24278785692bbb00eede Mon Sep 17 00:00:00 2001 From: Shivang Date: Wed, 26 Aug 2026 22:43:07 -0700 Subject: [PATCH 06/10] perf: make the text fast path unconditional, verified by pixel comparison Blank batching and the ASCII probe skip come off their flag and ship on. Measured on the shipped defaults: drawText calls drop 208 -> 30 per frame on tui and 176 -> 60 on scroll, with paint cost 11.26 -> 10.24 ms and 5.63 -> 2.30 ms. This change fails by producing a wrong PICTURE, not a wrong value, so no unit test would catch a regression. The existing tests pin what is checkable - the ASCII guard never skips a probe that would have fired, and the blank trim never drops a character - but neither of those sees a glyph in the wrong place. So it was verified by rendering benchmark/latency/unicode-torture.sh twice, with the fast path off and on, capturing the window both times, and diffing the images. ZWJ families, flags, skin tones, variation selectors, CJK, powerline glyphs, underlines spanning gaps, bold/italic, inverse, truecolour runs and aligned columns are identical apart from subpixel antialiasing: 0.31% of pixels, thin glyph outlines, no positional drift. Column alignment was checked specifically rather than inferred from the pixel count. A merged run advances by font metrics rather than by cell origin, so it could drift progressively along a line while a whole-image diff still looked small. Cropping the aligned table from both frames shows the columns landing on the same pixels. The fixture is committed because it is the regression asset for the next renderer change, and README.md now states the method rather than the flag. Caveat carried forward: cutting draw calls 86% bought only ~9% of paint time on tui. Caching TextLayoutResult or a Skia TextBlob fast path attack that same small slice. Per-cell scan and colour-conversion work in the two full-grid passes is where renderer effort should go next. --- benchmark/latency/README.md | 53 ++++++++----------- benchmark/latency/unicode-torture.sh | 32 +++++++++++ .../LATENCY_BASELINE_2026-08-27.md | 33 ++++++++---- .../rendering/TerminalCanvasRenderer.kt | 16 +----- 4 files changed, 78 insertions(+), 56 deletions(-) create mode 100755 benchmark/latency/unicode-torture.sh diff --git a/benchmark/latency/README.md b/benchmark/latency/README.md index 3231799d8..7db6e3511 100644 --- a/benchmark/latency/README.md +++ b/benchmark/latency/README.md @@ -58,38 +58,27 @@ BOSSTERM_FRAME_PROBE=1 ./gradlew :bossterm-app:run --no-daemon Workload (e) is the one that exposes scrollback-dependent cost: run it in the *same* tab as a preceding `bulk`, never a fresh one. -## A/B without a rebuild - -Two configurations can be compared inside one process, against the same warmed JIT and the -same window geometry, which removes the largest source of run-to-run noise: - -| Knob | Baseline | Alternative | -|---|---|---| -| `BOSSTERM_REDRAW_DEBOUNCE_MS` | unset (8 ms) | `0` | -| `BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS` | unset (50 ms) | `0` | -| `BOSSTERM_FAST_TEXT` | unset | `1` | -| `performanceMode` in `~/.bossterm/settings.json` | `balanced` | `latency` | - -`BOSSTERM_FAST_TEXT` turns on the renderer reductions: ASCII cells skip the grapheme -sequence probes, and blanks extend a batched run instead of flushing it (one `drawText` per -line rather than per word). Watch `drawCallsPerFrame` and `paintCostMs` for its effect; -`byteToPaintMs` should follow only if paint cost was actually on the critical path. - -All three env vars are measurement scaffolding and come out once the questions they answer -are settled. With none set, the build behaves exactly as shipped, so a run with no env is a -true baseline. - -Suggested ladder, one workload at a time, resetting between each: - -1. nothing set - baseline -2. `performanceMode=latency` - removes the 5 ms data-stream poll -3. `+ BOSSTERM_REDRAW_DEBOUNCE_MS=0` - removes the 8 ms interactive debounce -4. `+ BOSSTERM_HIGH_VOLUME_DEBOUNCE_MS=0` - removes the 50 ms bulk-output throttle -5. `+ BOSSTERM_FAST_TEXT=1` - renderer reductions - -Step 4 is the one to watch for regressions rather than gains: if paint cost is still high, -removing the throttle can cost throughput without buying latency. That is the measurement -that decides whether the renderer work in step 5 is a prerequisite or an optimisation. +## What shipped, and what it bought + +Measured on this harness, then made default (no flags remain): + +| change | effect | +|---|---| +| redraw debounce removed (was 8 ms, 50 ms under load) | interactive echo 16.4 ms -> ~2-4 ms | +| `performanceMode` default `balanced` -> `latency` | ~4 ms of that, on its own | +| blanks extend a batched run; ASCII cells skip the grapheme probes | `drawText` 208 -> 30 per frame on `tui`, 176 -> 60 on `scroll` | + +Not fixed, and not a render problem: bulk output still shows a ~1.2 s p95 on a 5 MB `cat`. +`triggerToPaint` there is single-digit milliseconds, so the time is queue wait and parse, +upstream of anything the renderer or the debounce controls. + +## Verifying a renderer change + +A renderer change fails by producing a wrong *picture*, which no unit test sees. Render +`unicode-torture.sh` twice, once before and once after, capture the window both times, and +diff the two images. Check column alignment specifically: a merged glyph run that advances by +font metrics rather than by cell width drifts progressively along a line, which a +whole-image pixel count will not make obvious. ## External anchor - do this once diff --git a/benchmark/latency/unicode-torture.sh b/benchmark/latency/unicode-torture.sh new file mode 100755 index 000000000..613edcaf8 --- /dev/null +++ b/benchmark/latency/unicode-torture.sh @@ -0,0 +1,32 @@ +#!/usr/bin/env bash +# Every construct the text pass special-cases, on one screen. +# +# The fast text path (blank batching + the ASCII probe skip) is the one change here that can +# fail silently: it produces a WRONG PICTURE rather than a wrong value, so no unit test sees +# it. This fixture exists to be rendered twice, with the fast path off and on, and the two +# frames compared pixel for pixel. +# +# Deliberately heavy on runs of spaces, because that is exactly what blank batching changes: +# aligned columns, indentation, and trailing gaps under an underline. +printf '\033[2J\033[H' +echo "ascii the quick brown fox jumps over the lazy dog 0123456789" +echo "aligned name size modified mode" +echo "aligned src/ 4096 Aug 26 10:11 drwxr-xr-x" +echo "aligned README.md 1024 Aug 26 10:12 -rw-r--r--" +printf 'zwj \xF0\x9F\x91\xA8\xE2\x80\x8D\xF0\x9F\x92\xBB family \xF0\x9F\x91\xA9\xE2\x80\x8D\xF0\x9F\x91\xA9\xE2\x80\x8D\xF0\x9F\x91\xA7 end\n' +printf 'flags \xF0\x9F\x87\xBA\xF0\x9F\x87\xB8 \xF0\x9F\x87\xAF\xF0\x9F\x87\xB5 \xF0\x9F\x87\xAE\xF0\x9F\x87\xB3 end\n' +printf 'skintone \xF0\x9F\x91\x8B\xF0\x9F\x8F\xBD \xF0\x9F\x91\x8D\xF0\x9F\x8F\xBF end\n' +printf 'varsel \xE2\x9C\x94\xEF\xB8\x8F \xE2\x9A\xA0\xEF\xB8\x8F \xE2\x9D\xA4\xEF\xB8\x8F end\n' +printf 'cjk \xE4\xBD\xA0\xE5\xA5\xBD\xE4\xB8\x96\xE7\x95\x8C \xE3\x81\x93\xE3\x82\x93\xE3\x81\xAB\xE3\x81\xA1\xE3\x81\xAF end\n' +printf 'powerline \xEE\x82\xB0 \xEE\x82\xB1 \xEE\x82\xB2 \xEE\x82\xB3 end\n' +printf 'underline \033[4munderlined with gaps\033[0m and \033[4mtrailing \033[0m|\n' +printf 'bold/italic \033[1mbold text\033[0m \033[3mitalic text\033[0m \033[1;3mboth\033[0m\n' +printf 'truecolor ' +for i in 0 1 2 3 4 5 6 7; do printf '\033[38;2;%d;%d;%dm block \033[0m' $((i*31)) $((255-i*31)) $((i*17)); done +printf '\n' +printf 'inverse \033[7m inverse with spaces \033[0m end\n' +printf 'bg runs \033[41m red \033[42m green \033[44m blue \033[0m end\n' +printf 'trailing text with trailing spaces \n' +printf 'leading indented by many spaces\n' +printf 'dim \033[2mdim text here\033[0m end\n' +echo diff --git a/benchmark_results/LATENCY_BASELINE_2026-08-27.md b/benchmark_results/LATENCY_BASELINE_2026-08-27.md index b4cac1247..8e878dd67 100644 --- a/benchmark_results/LATENCY_BASELINE_2026-08-27.md +++ b/benchmark_results/LATENCY_BASELINE_2026-08-27.md @@ -40,10 +40,9 @@ this file reported 262-917 ms numbers that were entirely this artefact. | bulk | latency mode only | 196.6 | 1441.8 | 2.56 | - | | bulk | **shipped defaults** | 491.5 | **983.0** | 4.10 | 128 | | tui | baseline | 9.2 | 15.4 | 11.26 | 208 | -| tui | fast-text only | 8.2 | 15.4 | 9.22 | **28** | -| tui | shipped defaults | 13.3 | 15.4 | 12.29 | 208 | +| tui | **shipped defaults (all on)** | 11.3 | 12.3 | 10.24 | **30** | | scroll | baseline | 41.0 | 73.7 | 5.63 | 176 | -| scroll | shipped defaults | 20.5 | 65.5 | 4.61 | 176 | +| scroll | **shipped defaults (all on)** | 45.1 | 98.3 | **2.30** | **60** | The `interactive` and `bulk` "shipped defaults" rows are the median of three consecutive runs each; they were tight (interactive p50 1.9/2.3/2.0, bulk p95 983.0 three times). @@ -88,11 +87,25 @@ That is a different piece of work from anything on this branch. ## Also measured, and worth knowing before scoping renderer work -**Draw-call count is not the dominant paint cost.** Blank batching (`BOSSTERM_FAST_TEXT=1`) -cut `drawText` calls 208 -> 28 per frame on `tui`, an 86% reduction, while `paintCost` moved -only 11.26 -> 9.22 ms, 19%. Caching `TextLayoutResult`, or dropping to a Skia `TextBlob` fast -path, both attack that same 19% slice. The per-cell scan and colour-conversion work in the two -full-grid passes is the bigger target. +**Draw-call count is not the dominant paint cost.** Blank batching cut `drawText` calls +208 -> 30 per frame on `tui`, an 86% reduction, while `paintCost` moved only 11.26 -> 10.24 ms. +On `scroll` the same change took draw calls 176 -> 60 and paint cost 5.63 -> 2.30 ms, which is +a better return but still nothing like proportional. + +The consequence for planning: caching `TextLayoutResult`, or dropping to a Skia `TextBlob` +fast path, both attack the slice that run-merging just showed is small. The per-cell scan and +colour-conversion work in the two full-grid passes is the bigger target, and that is where +renderer work should go next. + +**The renderer change was verified by pixel comparison, not by tests.** Blank batching and +the ASCII probe skip fail by producing a wrong *picture*, which no unit test sees. So +`benchmark/latency/unicode-torture.sh` was rendered twice, with the fast path off and on, and +the two window captures diffed: ZWJ families, flags, skin tones, variation selectors, CJK, +powerline glyphs, underlines spanning gaps, bold/italic, inverse, truecolour runs and aligned +columns are pixel-identical apart from subpixel antialiasing (0.31% of pixels, thin glyph +outlines, no positional drift). Column alignment in particular was checked directly, since a +merged run advancing by font metrics rather than cell width would drift progressively along +a line. It does not. **Recomposition is not a bottleneck.** `triggerToPaint` covers recomposition, layout and draw; it is 1.8-13.3 ms and tracks `paintCost` closely. The 2400-line `ProperTerminal` recomposing @@ -114,5 +127,5 @@ BOSSTERM_FRAME_PROBE=1 ./gradlew :bossterm-app:run --no-daemon ./benchmark/latency/probe.sh show ``` -`BOSSTERM_FAST_TEXT=1` enables the renderer reductions, which remain opt-in. **Raise the -window before every run** or finding 0 will dominate the result. +Everything measured here shipped as a default; no flags remain. **Raise the window before +every run** or finding 0 will dominate the result. diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt index 84b2467cd..29f22c0d2 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/TerminalCanvasRenderer.kt @@ -438,18 +438,6 @@ internal fun imageCellSlice( ) } -/** - * MEASUREMENT SCAFFOLDING - `BOSSTERM_FAST_TEXT=1`. - * - * Gates the renderer-side reductions so one process can A/B them against the same warmed - * JIT, window geometry and shell history as the baseline. Rebuilding and relaunching between - * samples is the largest source of run-to-run noise in a latency measurement and it is - * avoidable here. The flag comes out, and the fast path becomes unconditional, once the - * numbers say what it is worth. - */ -private val fastTextPath: Boolean = - System.getenv("BOSSTERM_FAST_TEXT").let { it == "1" || it.equals("true", ignoreCase = true) } - /** * How much of a batched run actually needs shaping. * @@ -981,7 +969,7 @@ object TerminalCanvasRenderer { // fire, so the 20-char lookahead, the String it builds and the three scans are // dead work - per cell, per frame, on every line of a log, a diff or source // code. Anything non-ASCII nearby takes the original path unchanged. - val plainAscii = fastTextPath && isPlainAsciiRun(line, col, bufferLimit) + val plainAscii = isPlainAsciiRun(line, col, bufferLimit) // Check for ZWJ sequences using ThreadLocal builder (issue #143 optimization) val builder = zwjCheckBuilder.get() @@ -1104,7 +1092,7 @@ object TerminalCanvasRenderer { val canBatch = analysis.lowSurrogate == null && !analysis.isDoubleWidth && !analysis.isEmojiOrWideSymbol && !analysis.isCursiveOrMath && !analysis.isTechnicalSymbol && !isHidden && isBlinkVisible && - (!isBlankCell || (fastTextPath && batchText.isNotEmpty())) + (!isBlankCell || batchText.isNotEmpty()) val styleMatches = batchText.isNotEmpty() && (isBlankCell || batchFgColor == fgColor) && From 610538b128e1a4d6f411a5974f81ccf89900d00a Mon Sep 17 00:00:00 2001 From: Shivang Date: Thu, 27 Aug 2026 03:08:04 -0400 Subject: [PATCH 07/10] perf: stop the debug collector deep-copying the buffer 10x/sec when nobody is watching Profiling a 5 MB `cat` put 59% of execution samples (55 of 93) in DebugDataCollector: 32 TextEntries.add <- TerminalLine.copy <- TerminalTextBuffer.createSnapshot <- DebugDataCollector.captureState 15 TerminalLine.copy <- createSnapshot <- captureState 7 ConcurrentLinkedQueue.size <- DebugDataCollector.recordChunk 1 String.toCharArray <- recordChunk Two independent problems, both on by default: 1. captureState() ran on a 100 ms timer for the life of every tab and called createSnapshot() - the FULL deep copy, every line of screen AND history cloned. debugModeEnabled defaults to false, so all of it was thrown away. The collector's own `enabled` flag defaults true and setEnabled() has no callers anywhere, so nothing ever turned it off. It now returns early unless the tab's debug panel is actually open. The loop keeps ticking rather than being torn down, because the panel toggles at runtime (Cmd/Ctrl+Shift+D) and must start showing data immediately. 2. Both ring buffers trimmed with `while (queue.size > max) queue.poll()`. ConcurrentLinkedQueue.size() is O(n): it walks the list. With maxChunks=1000 that is up to 1000 node traversals per chunk, on the PTY reader thread, for every chunk that crossed the tty. Now trimmed against a tracked counter. The counter shadows a queue, and drift is silent and directional - too high and the ring evicts live entries forever, too low and it grows unbounded. Neither throws; read_debug_console would just return the wrong window of history. So the invariant is tested, including that clear() resets both. Removing the reset makes clearResetsTheCounterAlongsideTheQueue fail. NOT YET VERIFIED BY MEASUREMENT. The profile is strong evidence for the diagnosis, but the before/after number is missing: the display went to sleep, and measuring a terminal on a dark screen reproduces the ~3 fps occlusion artefact documented as finding 0 in the baseline. Numbers taken now would be that artefact, not this fix. The bulk figures in LATENCY_BASELINE stand unchanged until a run on a live display says otherwise. Also adds queueWaitMs to the probe, which is what identified the bottleneck as upstream of rendering: on bulk, queue wait p50 was 1179 ms against a byteToPaint p50 of 1048 ms, i.e. essentially all of it, with 5393 chunks for 5.5M chars (~1022 chars per chunk - PTY reads return far less than the 8 KiB requested). --- .../compose/debug/DebugDataCollector.kt | 52 ++++++++++++--- .../compose/rendering/FrameLatencyProbe.kt | 27 ++++++++ .../terminal/BlockingTerminalDataStream.kt | 5 +- .../debug/DebugDataCollectorTrimTest.kt | 63 +++++++++++++++++++ 4 files changed, 136 insertions(+), 11 deletions(-) create mode 100644 compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt index 6bf9a19ac..0ff560238 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt @@ -39,6 +39,28 @@ class DebugDataCollector( private val snapshots = ConcurrentLinkedQueue() private val chunkIndex = AtomicInteger(0) + /** + * Sizes of [chunks] and [snapshots], tracked rather than asked for. + * + * `ConcurrentLinkedQueue.size()` is O(n): it walks the list. Both ring buffers trimmed + * with `while (queue.size > max) queue.poll()`, so every chunk that crossed the tty paid + * an O(maxChunks) scan - 1000 node traversals per chunk, on the PTY reader thread. + */ + private val chunkCount = AtomicInteger(0) + private val snapshotCount = AtomicInteger(0) + + /** Drop entries until [count] is back within [max]. */ + private fun trim(queue: ConcurrentLinkedQueue, count: AtomicInteger, max: Int) { + while (count.get() > max) { + if (queue.poll() == null) { + // Someone else drained it; do not let the counter drift below the queue. + count.set(queue.size) + return + } + count.decrementAndGet() + } + } + @Volatile private var enabled = true @@ -66,11 +88,8 @@ class DebugDataCollector( ) chunks.offer(chunk) - - // Trim to maxChunks (circular buffer) - while (chunks.size > maxChunks) { - chunks.poll() - } + chunkCount.incrementAndGet() + trim(chunks, chunkCount, maxChunks) // Write to file log if active writeChunkToFile(chunk) @@ -88,6 +107,18 @@ class DebugDataCollector( val currentTab = tab ?: return // Skip if tab not set yet + // Nobody is looking: skip the snapshot entirely. + // + // This is not a micro-optimisation. `createSnapshot()` is the FULL deep copy - every + // line in the buffer, screen and history, cloned - and this runs on a timer every + // `debugCaptureInterval` (100 ms) for the life of every tab. With the debug panel + // off, which is the default (`debugModeEnabled = false`), all of it was thrown away. + // Profiling a 5 MB `cat` put 59% of samples in this call chain. + // + // The loop keeps ticking rather than being torn down, because the panel can be + // toggled at any time (Cmd/Ctrl+Shift+D) and must start showing data immediately. + if (!currentTab.debugEnabled.value) return + try { val textBuffer = currentTab.textBuffer val terminal = currentTab.terminal @@ -133,11 +164,8 @@ class DebugDataCollector( ) snapshots.offer(snapshot) - - // Trim to maxSnapshots (circular buffer) - while (snapshots.size > maxSnapshots) { - snapshots.poll() - } + snapshotCount.incrementAndGet() + trim(snapshots, snapshotCount, maxSnapshots) } catch (e: Exception) { println("WARN: Failed to capture terminal state: ${e.message}") @@ -232,6 +260,10 @@ class DebugDataCollector( fun clear() { chunks.clear() snapshots.clear() + // Counters shadow the queues; clearing one without the other would make trim() + // evict live entries forever. + chunkCount.set(0) + snapshotCount.set(0) chunkIndex.set(0) } diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt index ed8209b53..2334f1de4 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/rendering/FrameLatencyProbe.kt @@ -80,6 +80,19 @@ object FrameLatencyProbe { * long debounce are indistinguishable, and they have opposite fixes. */ val triggerToPaint: Histogram = Histogram() + + /** + * How long a PTY chunk sat in the data-stream queue before the emulator took it. + * + * Recorded per chunk, not per paint: this is the one series that says whether bulk + * output is slow because the parser cannot keep up (queue backs up) or because + * something downstream of the parse is stalling. Those have completely different fixes. + */ + val queueWait: Histogram = Histogram() + + /** Total bytes' worth of chunks dequeued, so a sustained parse rate can be derived. */ + private val chunksDequeued = AtomicLong(0) + private val charsDequeued = AtomicLong(0) val paintCost: Histogram = Histogram() val snapshotCost: Histogram = Histogram() val drawCallsPerFrame: Histogram = Histogram() @@ -150,6 +163,9 @@ object FrameLatencyProbe { .append(",\n") append(" \"byteToPaintMs\": ").append(byteToPaint.jsonMillis()).append(",\n") append(" \"triggerToPaintMs\": ").append(triggerToPaint.jsonMillis()).append(",\n") + append(" \"queueWaitMs\": ").append(queueWait.jsonMillis()).append(",\n") + append(" \"chunksDequeued\": ").append(chunksDequeued.get()).append(",\n") + append(" \"charsDequeued\": ").append(charsDequeued.get()).append(",\n") append(" \"paintCostMs\": ").append(paintCost.jsonMillis()).append(",\n") append(" \"lockedCaptureMs\": ").append(snapshotCost.jsonMillis()).append(",\n") append(" \"drawCallsPerFrame\": ").append(drawCallsPerFrame.jsonRaw()).append(",\n") @@ -170,6 +186,14 @@ object FrameLatencyProbe { pendingArrival.compareAndSet(NONE, nanos) } + /** A chunk of [length] chars left the queue after waiting since [arrivalNanos]. */ + fun markDequeued(arrivalNanos: Long, length: Int) { + if (!enabled) return + queueWait.recordNanos(System.nanoTime() - arrivalNanos) + chunksDequeued.incrementAndGet() + charsDequeued.addAndGet(length.toLong()) + } + /** Timestamp for a later `record*` call, or 0 when the probe is off. */ fun startTiming(): Long = if (enabled) System.nanoTime() else 0L @@ -219,6 +243,9 @@ object FrameLatencyProbe { fun reset() { byteToPaint.reset() triggerToPaint.reset() + queueWait.reset() + chunksDequeued.set(0) + charsDequeued.set(0) paintCost.reset() snapshotCost.reset() drawCallsPerFrame.reset() diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt index 1a69a10d5..0af392f49 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/terminal/BlockingTerminalDataStream.kt @@ -82,7 +82,10 @@ class BlockingTerminalDataStream( /** Pair every successful take from [dataQueue] with its arrival stamp. */ private fun took(chunk: String?): String? { if (FrameLatencyProbe.enabled && chunk != null && chunk != CLOSE_SENTINEL) { - arrivalNanos.poll()?.let(FrameLatencyProbe::markArrival) + arrivalNanos.poll()?.let { stamped -> + FrameLatencyProbe.markArrival(stamped) + FrameLatencyProbe.markDequeued(stamped, chunk.length) + } } return chunk } diff --git a/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt new file mode 100644 index 000000000..6ba83defe --- /dev/null +++ b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt @@ -0,0 +1,63 @@ +package ai.rever.bossterm.compose.debug + +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertTrue + +/** + * The chunk ring is trimmed against a tracked counter rather than `ConcurrentLinkedQueue.size()`, + * which is O(n) and was being called once per chunk that crossed the tty. + * + * A tracked counter can drift from the queue it shadows, and drift is silent and directional: + * too high and the ring evicts live entries forever, too low and it grows without bound. Neither + * shows up as an exception, and `read_debug_console` would just quietly return the wrong window + * of history. So the invariant is pinned here rather than assumed. + */ +class DebugDataCollectorTrimTest { + + @Test + fun ringStaysAtItsBoundUnderSustainedRecording() { + val max = 16 + val collector = DebugDataCollector(tab = null, maxChunks = max, maxSnapshots = 4) + + repeat(max * 20) { collector.recordChunk("chunk-$it", ChunkSource.PTY_OUTPUT) } + + assertEquals(max, collector.getChunkCount(), "ring should sit exactly at its bound") + assertEquals(max, collector.getDebugChunks().size, "counter and queue must agree") + } + + @Test + fun theRetainedWindowIsTheMostRecent() { + // Evicting from the wrong end would keep the oldest history and silently drop + // everything a caller actually wants. + val max = 8 + val collector = DebugDataCollector(tab = null, maxChunks = max, maxSnapshots = 4) + repeat(50) { collector.recordChunk("chunk-$it", ChunkSource.PTY_OUTPUT) } + + val kept = collector.getDebugChunks().map { String(it.data) } + assertEquals((42..49).map { "chunk-$it" }, kept) + } + + @Test + fun clearResetsTheCounterAlongsideTheQueue() { + // The failure this guards is nasty: a counter left high after a clear makes every + // later record evict a live entry, so the ring never refills. + val max = 8 + val collector = DebugDataCollector(tab = null, maxChunks = max, maxSnapshots = 4) + repeat(40) { collector.recordChunk("before-$it", ChunkSource.PTY_OUTPUT) } + collector.clear() + assertEquals(0, collector.getChunkCount()) + + repeat(5) { collector.recordChunk("after-$it", ChunkSource.PTY_OUTPUT) } + assertEquals(5, collector.getChunkCount(), "ring must refill after a clear") + assertEquals(5, collector.getDebugChunks().size) + } + + @Test + fun growingBelowTheBoundDoesNotEvict() { + val collector = DebugDataCollector(tab = null, maxChunks = 100, maxSnapshots = 4) + repeat(30) { collector.recordChunk("c-$it", ChunkSource.PTY_OUTPUT) } + assertEquals(30, collector.getChunkCount()) + assertTrue(collector.getDebugChunks().first().data.concatToString() == "c-0") + } +} From 20898ba9ed794f3f9a88f7f03a6e986e3c0b4a0e Mon Sep 17 00:00:00 2001 From: Shivang Date: Thu, 27 Aug 2026 04:11:38 -0400 Subject: [PATCH 08/10] perf: fix the bulk-output PTY path (queue wait ~2.5x lower) Stack-sampled the emulator thread through a sustained cat loop. Three costs, none of which is visible from reading the code, and none of which was on my list from doing exactly that. 1. An exception per character (20% of parse time). drainTerminalEmulator loops `while (shouldContinue())`, and shouldContinue is handle::isAlive -> Process.hasExited() -> UnixPtyProcess.exitValue(), which THROWS IllegalThreadStateException whenever the child is alive - the normal case. Java catches it internally, so the call site looks free. A 5 MB cat built ~5.5 million exceptions with filled-in stack traces. isAlive() now caches for 20 ms and latches death. Safe because the drain loop's real termination signal is EOF from the data stream; this check is the belt-and-braces one. 2. An AWT event per redraw request (20%). requestRedraw trySends on the redraw channel; when the processor is parked each send resumes its continuation through the Swing dispatcher, which means EventQueue.invokeLater, an InvocationEvent, and an AccessController.getContext native stack walk. The emulator requests a redraw on every buffer mutation. A pending flag now skips the send when one is already queued, cleared before the redraw so a mutation landing mid-redraw still queues the next frame. 3. ICU grapheme segmentation on plain ASCII (~27%). segmentIntoGraphemes ran RuleBasedBreakIterator, a per-cluster substring and a width calculation over text that was ASCII end to end. Nothing below U+0080 is wide, ambiguous, combining, a surrogate, a ZWJ or a variation selector, so the answer is decidable without ICU. The ICU body is split into segmentViaBreakIterator so the fast path can be PROVED equivalent rather than argued to be: GraphemeAsciiFastPathTest compares the two over every printable ASCII character and a corpus of real terminal output. Loosening the guard to admit non-ASCII makes it fail. Measured on queueWaitMs, which has n~5400 per run (one sample per chunk) and is the reliable series here - byteToPaintMs sometimes lands only a handful of frames on this workload. p50 786-1179 ms -> 262-459 ms p95 1572-1966 ms -> 491-655 ms Bulk output is improved, not solved. What remains on the emulator thread: visualColToBufferCol (~9%), TerminalLine.toBuf/merge (~11%), residual AWT dispatch. Unicode rendering re-checked by rendering unicode-torture.sh on the new build: ZWJ families, flags, skin tones, variation selectors, CJK, powerline, underlines spanning gaps and aligned columns all correct. --- .../LATENCY_BASELINE_2026-08-27.md | 54 +++++++++++ .../bossterm/terminal/util/GraphemeUtils.kt | 50 +++++++++++ .../util/GraphemeAsciiFastPathTest.kt | 90 +++++++++++++++++++ .../compose/ComposeTerminalDisplay.kt | 30 ++++++- .../compose/PlatformServices.desktop.kt | 41 ++++++++- 5 files changed, 261 insertions(+), 4 deletions(-) create mode 100644 bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/GraphemeAsciiFastPathTest.kt diff --git a/benchmark_results/LATENCY_BASELINE_2026-08-27.md b/benchmark_results/LATENCY_BASELINE_2026-08-27.md index 8e878dd67..46ad2a63f 100644 --- a/benchmark_results/LATENCY_BASELINE_2026-08-27.md +++ b/benchmark_results/LATENCY_BASELINE_2026-08-27.md @@ -64,6 +64,60 @@ channel plus Compose's own per-frame coalescing already do the job the debounce --- +## Bulk output: profiled, then fixed (3 changes, ~2.5x) + +Measured as `queueWaitMs` p50/p95, the time a PTY chunk sits in the data-stream queue before +the emulator takes it. That series has n ~5400 per run (one sample per chunk), so it is the +reliable one here; `byteToPaintMs` on this workload sometimes lands only a handful of frames. + +| state | queueWait p50 | p95 | +|---|---|---| +| before | 786 - 1179 | 1572 - 1966 | +| + `isAlive()` cached, redraw sends coalesced | 524 - 655 | 1048 - 1180 | +| + ASCII grapheme fast path | **262 - 459** | **491 - 655** | + +Stack-sampling the emulator thread (`DefaultDispatcher-worker-N`, found by matching +`drainTerminalEmulator` in the stack) through a sustained `cat` loop found three costs, none +of which was visible from reading the code: + +**1. An exception per character (20% of parse time).** `drainTerminalEmulator` loops +`while (shouldContinue())`, and `shouldContinue` is `handle::isAlive` -> +`Process.hasExited()` -> `UnixPtyProcess.exitValue()`, which **throws +`IllegalThreadStateException` whenever the child is alive** - the normal case. Java catches +it internally, so the call site looks free. A 5 MB `cat` built ~5.5 million exceptions, each +with a filled-in stack trace. `isAlive()` now caches for 20 ms and latches death. + +**2. An AWT event per redraw request (20%).** `requestRedraw` does `trySend` on the redraw +channel; when the processor is parked, each send resumes its continuation through the Swing +dispatcher, which means `EventQueue.invokeLater`, an `InvocationEvent`, and an +`AccessController.getContext` native stack walk. The emulator requests a redraw on every +buffer mutation. A pending-flag now skips the send when one is already queued. + +**3. ICU grapheme segmentation on plain ASCII (~27%).** `segmentIntoGraphemes` ran the ICU +`RuleBasedBreakIterator`, a per-cluster substring and a width calculation over text that was +ASCII end to end. Nothing below U+0080 is wide, ambiguous, combining, a surrogate, a ZWJ or a +variation selector, so the answer is decidable without ICU. `GraphemeAsciiFastPathTest` +proves the fast path against the BreakIterator path it replaces, over every printable ASCII +character and a corpus of real terminal output; loosening the guard to admit non-ASCII makes +it fail. + +Still ~260-460 ms, so bulk output is improved rather than solved. What remains on the +emulator thread after these three: `ColumnConversionUtils.visualColToBufferCol` (~9%), +`TerminalLine.toBuf` / `merge` line rebuilding (~11%), and a residual AWT dispatch cost. + +### A fix that did not work, and why it looked like it would + +Profiling first pointed at `DebugDataCollector`: 59% of execution samples sat in +`captureState` -> `createSnapshot` -> `TerminalLine.copy`, a full deep copy of the whole +buffer on a 100 ms timer, for a debug panel that defaults to off. Gating it changed bulk +latency **not at all**. + +The samples were real; the inference was wrong. That work runs on `Dispatchers.IO` workers, +*parallel* to the parse, and `JavaMonitorEnter` events were zero - so it never blocked the +emulator thread. A whole-JVM profile answers "where is CPU spent", which is not the same +question as "what is the critical path". The fix was kept anyway (it removes 10 full-buffer +deep copies per second per tab of pure waste) but it is an idle-CPU fix, not this one. + ## Correction: the debounce does NOT own the bulk-output tail An earlier revision of this file claimed removing the debounce took `bulk` p95 from 1310 ms to diff --git a/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/GraphemeUtils.kt b/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/GraphemeUtils.kt index 1c7335a32..b6cb5bfda 100644 --- a/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/GraphemeUtils.kt +++ b/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/GraphemeUtils.kt @@ -168,9 +168,59 @@ object GraphemeUtils { * @param text The string to segment * @return List of grapheme clusters */ + /** + * True when every character is printable ASCII (U+0020..U+007E). + * + * Control characters are excluded deliberately: the emulator routes them separately and + * their width is not simply 1, so letting them into the fast path would be a behaviour + * change rather than an optimisation. + */ + internal fun isAllPrintableAscii(text: String): Boolean { + for (ch in text) { + if (ch.code < 0x20 || ch.code > 0x7E) return false + } + return true + } + + /** Interned single-character clusters for printable ASCII, built once. */ + private val asciiClusters: Array = Array(0x7F - 0x20) { i -> + val ch = (0x20 + i).toChar() + GraphemeCluster(ch.toString(), 1, intArrayOf(ch.code)) + } + + private fun asciiCluster(ch: Char): GraphemeCluster = asciiClusters[ch.code - 0x20] + fun segmentIntoGraphemes(text: String): List { if (text.isEmpty()) return emptyList() + // Printable ASCII cannot form a multi-character grapheme cluster and is always one + // column wide: no combining marks, no ZWJ, no variation selectors, no surrogates, + // nothing wide or ambiguous lives below U+0080. So the ICU BreakIterator, the + // per-cluster substring and the width calculation are all decidable without them. + // + // This is not a marginal case - it is essentially all terminal output. Stack + // sampling the emulator thread through a 5 MB `cat` put ~27% of its time in this + // call chain (`segmentIntoGraphemes` -> `calculateGraphemeWidth` -> + // `extractCodePoints` / `isEmojiPresentation` / `RuleBasedBreakIterator`), for text + // that was ASCII from end to end. + // + // Anything non-ASCII falls through to ICU unchanged; the boundary is one cheap scan. + if (isAllPrintableAscii(text)) { + return ArrayList(text.length).apply { + for (ch in text) add(asciiCluster(ch)) + } + } + + return segmentViaBreakIterator(text) + } + + /** + * The full ICU segmentation, split out so the ASCII fast path above can be proved + * equivalent to it rather than argued to be. + */ + internal fun segmentViaBreakIterator(text: String): List { + if (text.isEmpty()) return emptyList() + val result = mutableListOf() val iterator = breakIterator.get() iterator.setText(text) diff --git a/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/GraphemeAsciiFastPathTest.kt b/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/GraphemeAsciiFastPathTest.kt new file mode 100644 index 000000000..48070b78d --- /dev/null +++ b/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/GraphemeAsciiFastPathTest.kt @@ -0,0 +1,90 @@ +package ai.rever.bossterm.terminal.util + +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertFalse +import kotlin.test.assertTrue + +/** + * `segmentIntoGraphemes` skips ICU entirely for printable ASCII, which is essentially all + * terminal output. The claim is that ICU cannot disagree there: nothing below U+0080 is + * wide, ambiguous, combining, a surrogate, a ZWJ or a variation selector. + * + * That claim is checkable rather than arguable, so it is checked here - against the very + * BreakIterator path it replaces, over every printable ASCII character and a corpus of real + * terminal output. + */ +class GraphemeAsciiFastPathTest { + + private fun assertSameSegmentation(text: String) { + val fast = GraphemeUtils.segmentIntoGraphemes(text) + val icu = GraphemeUtils.segmentViaBreakIterator(text) + assertEquals(icu.size, fast.size, "cluster count differs for " + text.take(40)) + for (i in icu.indices) { + assertEquals(icu[i].text, fast[i].text, "cluster $i text differs") + assertEquals(icu[i].visualWidth, fast[i].visualWidth, "cluster $i width differs") + assertTrue( + icu[i].codePoints.contentEquals(fast[i].codePoints), + "cluster $i code points differ" + ) + } + } + + @Test + fun everyPrintableAsciiCharacterSegmentsIdentically() { + for (code in 0x20..0x7E) { + assertSameSegmentation(code.toChar().toString()) + } + } + + @Test + fun realTerminalOutputSegmentsIdentically() { + listOf( + "the quick brown fox jumps over the lazy dog 0123456789", + "drwxr-xr-x 12 user staff 384 Aug 26 10:11 src", + " INFO module-07 request completed in 42 ms path=/api/v1/x/9", + "a b c d e", + "!\"#\$%&'()*+,-./:;<=>?@[\\]^_`{|}~" + ).forEach(::assertSameSegmentation) + } + + @Test + fun nonAsciiStillGoesThroughIcu() { + // The guard must reject anything ICU could segment differently, or the fast path + // would flatten a family emoji into several one-column clusters. + listOf( + "👨‍💻", // ZWJ: man technologist + "🇺🇸", // regional indicators: flag + "👋🏽", // skin tone modifier + "✔️", // variation selector + "你好", // CJK + "é", // combining acute + "ascii then 你" // mixed + ).forEach { text -> + assertFalse( + GraphemeUtils.isAllPrintableAscii(text), + "guard must not claim this is plain ASCII" + ) + assertSameSegmentation(text) + } + } + + @Test + fun controlCharactersAreNotTakenByTheFastPath() { + // Their width is not simply 1, so admitting them would be a behaviour change + // rather than an optimisation. + assertFalse(GraphemeUtils.isAllPrintableAscii("a\tb")) + assertFalse(GraphemeUtils.isAllPrintableAscii("a\nb")) + assertFalse(GraphemeUtils.isAllPrintableAscii("a\u0000b")) + assertFalse(GraphemeUtils.isAllPrintableAscii("a\u007Fb")) + // A plain space, by contrast, IS printable ASCII and must stay on the fast + // path - it is the most common character in terminal output. + assertTrue(GraphemeUtils.isAllPrintableAscii("a b")) + } + + @Test + fun theFastPathActuallyEngages() { + // A guard that never fires would pass every check above while changing nothing. + assertTrue(GraphemeUtils.isAllPrintableAscii("plain ascii line 123")) + } +} diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt index 71da1522a..9ffbba1ac 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/ComposeTerminalDisplay.kt @@ -69,6 +69,22 @@ class ComposeTerminalDisplay : TerminalDisplay { // Channel for queuing redraw requests with conflation private val redrawChannel = Channel(Channel.CONFLATED) + /** + * Whether a redraw is already queued and unclaimed. + * + * The channel is CONFLATED, so a second `trySend` is harmless to correctness - but it + * is NOT free. When the processor is parked on the channel, each send resumes its + * continuation through the Swing dispatcher, and that means `EventQueue.invokeLater`, + * an `InvocationEvent`, and an `AccessController.getContext` stack walk, per call. The + * emulator requests a redraw on every buffer mutation, so bulk output turned that into + * an AWT event storm: stack-sampling the parse thread under load put 20% of its time + * in `AWTEvent.` beneath `requestRedraw`. + * + * Cleared by the processor BEFORE it redraws, so a mutation that lands during a redraw + * still schedules the next one. + */ + private val redrawQueued = java.util.concurrent.atomic.AtomicBoolean(false) + // Coroutine scope for redraw processing private val redrawScope = CoroutineScope(Dispatchers.Main + SupervisorJob()) @@ -320,6 +336,9 @@ class ComposeTerminalDisplay : TerminalDisplay { try { for (request in redrawChannel) { + // Released before the redraw, not after, so a buffer mutation that + // lands mid-redraw still queues the next frame. + redrawQueued.set(false) try { // Re-check sync mode: a ?2026h may have arrived after this // redraw was queued (e.g., rapid ?2026l/?2026h toggle by CLIs @@ -365,9 +384,14 @@ class ComposeTerminalDisplay : TerminalDisplay { } } - // Conflated channel: a full channel simply coalesces this request into the - // pending one, which is the intended debouncing behaviour. - redrawChannel.trySend(RedrawRequest()) + // Skip the send entirely when one is already pending: see [redrawQueued]. + if (redrawQueued.compareAndSet(false, true)) { + // Release the claim if the send did not land, or a closed channel would latch + // the flag and silently stop every future redraw. + if (redrawChannel.trySend(RedrawRequest()).isFailure) { + redrawQueued.set(false) + } + } } /** diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/PlatformServices.desktop.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/PlatformServices.desktop.kt index 5511f27dd..1bb5a3e6b 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/PlatformServices.desktop.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/PlatformServices.desktop.kt @@ -168,6 +168,11 @@ class DesktopProcessService( */ private val isShuttingDown = java.util.concurrent.atomic.AtomicBoolean(false) + private companion object { + /** 20 ms: far longer than a parse step, far shorter than a human notices. */ + const val ALIVE_CACHE_NANOS = 20_000_000L + } + override suspend fun write(data: String) { outputStream.write(data.toByteArray()) outputStream.flush() @@ -269,7 +274,41 @@ class DesktopProcessService( return bytes.size } - override fun isAlive(): Boolean = process.isAlive + /** + * Liveness, cached for [ALIVE_CACHE_NANOS]. + * + * `Process.isAlive()` calls `hasExited()`, which on pty4j calls + * `UnixPtyProcess.exitValue()` and lets it THROW `IllegalThreadStateException` + * whenever the child is still running - the normal case. Java catches it, so the + * cost is invisible at the call site: a full exception with a filled-in stack + * trace, every call. + * + * The emulator drain loop calls this once per CHARACTER + * (`drainTerminalEmulator`'s `while (shouldContinue())`), so a 5 MB `cat` built + * ~5.5 million exceptions. Stack-sampling the parse thread under load put 20% of + * its time in `Throwable.fillInStackTrace` beneath this call. + * + * A short TTL is safe here because nothing depends on sub-millisecond precision: + * the drain loop's real termination signal is EOF from the data stream, which the + * PTY reader closes when the child goes away. This check is the belt-and-braces + * one. Death is also latched - a process that has exited never comes back, so a + * false result is cached forever and never pays the syscall again. + */ + override fun isAlive(): Boolean { + if (knownDead) return false + val now = System.nanoTime() + val checked = aliveCheckedAtNanos + if (checked != 0L && now - checked < ALIVE_CACHE_NANOS) return cachedAlive + val alive = process.isAlive + cachedAlive = alive + aliveCheckedAtNanos = now + if (!alive) knownDead = true + return alive + } + + @Volatile private var cachedAlive: Boolean = true + @Volatile private var aliveCheckedAtNanos: Long = 0L + @Volatile private var knownDead: Boolean = false override suspend fun kill() { // Signal shutdown to prevent race conditions with read() From 07e12cd195be975161297ecb6b7ae791a31fe5a0 Mon Sep 17 00:00:00 2001 From: Shivang Date: Thu, 27 Aug 2026 05:23:10 -0400 Subject: [PATCH 09/10] perf: skip the column walk on lines that need no visual mapping BossTerminal.wrapLines calls visualColToBufferCol(line, terminalWidth, length) - a walk from column 0 to the full terminal width, with an O(runs) charAt inside it - every time a line wraps. For output wider than the window that is every line. Stack sampling the emulator thread through a sustained cat put ~10% of its time there, and every one of those samples came from that single call site. A line that needs no visual-column mapping holds nothing above U+007F: no double-width character, no DWC marker (U+E000), no combining mark, no surrogate. Buffer column and terminal cell are then the same number, so the answer is the identity clamped to the line. TerminalLine already tracks the flag; the conversion now short-circuits on it, which the renderer's hit-testing benefits from too. Measured on queueWaitMs (n~5400 per run, 3 runs): p50 262-459 ms -> 147-262 ms p95 491-655 ms -> 262-360 ms That is ~5x on the bulk queue wait end to end for this branch (from 786-1179 ms). The guard is the entire correctness argument, so it is tested against a line carrying DWC markers. Worth recording how: the first version of that test asserted only columns where the identity happens to agree, and passed against a build with the guard deleted. The assertions that bite are the SECOND cell of each wide character, where the buffer index must snap back to the glyph's start instead of landing on the DWC marker. Deleting the guard now fails it. Also commits TerminalLineWriteModelTest, which is not needed by this change. TerminalLine.merge is the other remaining hot spot (~12% of non-parked emulator time): writeCharacters rebuilds the whole line through toBuf and re-derives every style run whenever a write lands anywhere but the end, which - since lines are NUL-filled to width - is most writes. The rope-style entry walk that would fix it is NOT a safe drop-in: collectFromBuffer coalesces adjacent runs with reference-equal styles and an entry walk does not, so without matching that, every overwrite fragments the line further and charAt is O(entries). That trades a one-off O(lineLength) rebuild for a permanently slower line, and it would not show up in a five-second benchmark - only in a long session. It needs run coalescing across the splice boundaries and deserves its own change. The model test is the harness for whoever does it: a randomised check pinning what writeString must produce cell by cell, independent of how the line is stored. --- .../LATENCY_BASELINE_2026-08-27.md | 45 +++++- .../terminal/util/ColumnConversionUtils.kt | 12 ++ .../model/TerminalLineWriteModelTest.kt | 138 ++++++++++++++++++ .../util/ColumnConversionFastPathTest.kt | 83 +++++++++++ 4 files changed, 274 insertions(+), 4 deletions(-) create mode 100644 bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/model/TerminalLineWriteModelTest.kt create mode 100644 bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionFastPathTest.kt diff --git a/benchmark_results/LATENCY_BASELINE_2026-08-27.md b/benchmark_results/LATENCY_BASELINE_2026-08-27.md index 46ad2a63f..332c92040 100644 --- a/benchmark_results/LATENCY_BASELINE_2026-08-27.md +++ b/benchmark_results/LATENCY_BASELINE_2026-08-27.md @@ -74,7 +74,10 @@ reliable one here; `byteToPaintMs` on this workload sometimes lands only a handf |---|---|---| | before | 786 - 1179 | 1572 - 1966 | | + `isAlive()` cached, redraw sends coalesced | 524 - 655 | 1048 - 1180 | -| + ASCII grapheme fast path | **262 - 459** | **491 - 655** | +| + ASCII grapheme fast path | 262 - 459 | 491 - 655 | +| + `visualColToBufferCol` fast path | **147 - 262** | **262 - 360** | + +End to end that is roughly **5x** on the bulk queue wait (786-1179 -> 147-262 ms p50). Stack-sampling the emulator thread (`DefaultDispatcher-worker-N`, found by matching `drainTerminalEmulator` in the stack) through a sustained `cat` loop found three costs, none @@ -101,9 +104,43 @@ proves the fast path against the BreakIterator path it replaces, over every prin character and a corpus of real terminal output; loosening the guard to admit non-ASCII makes it fail. -Still ~260-460 ms, so bulk output is improved rather than solved. What remains on the -emulator thread after these three: `ColumnConversionUtils.visualColToBufferCol` (~9%), -`TerminalLine.toBuf` / `merge` line rebuilding (~11%), and a residual AWT dispatch cost. +**4. Column conversion on every line wrap (~10%, all of it from one call site).** +`BossTerminal.wrapLines` calls `visualColToBufferCol(line, terminalWidth, line.length())` - +a walk from column 0 to the full width, with an O(runs) `charAt` inside it - every time a +line wraps, which for output wider than the window is every line. A line that needs no +visual-column mapping holds nothing above U+007F, so buffer column and terminal cell are the +same number and the answer is the identity. `ColumnConversionUtils` now short-circuits on +`line.requiresVisualColumnMapping`, which benefits the renderer's hit-testing too. + +That guard IS the correctness argument, so it is tested against a line carrying DWC markers. +Worth noting how that test was arrived at: the first version asserted only columns where the +identity happens to agree, so it passed against a deliberately broken build. The assertions +that matter are the second cell of each wide character, where the buffer index has to snap +back to the glyph's start rather than land on the DWC marker. + +Still ~150-260 ms, so bulk output is improved rather than solved. What remains on the +emulator thread: `TerminalLine.toBuf` / `merge` (~12% of non-parked time), residual AWT +dispatch (~20%), and `joinTo` / `appendElement` string building (~10%). + +### `TerminalLine.merge`: analysed, deliberately not shipped + +`writeCharacters` rebuilds the ENTIRE line through `toBuf` (a `CharArray` plus a +`TextStyle` array of the full line length) and re-derives every style run, whenever a write +lands anywhere but the end. Lines are NUL-filled to width, so that is most writes. + +The obvious fix is a rope-style entry walk: keep the untouched entries, split only the ones +the write overlaps. It is O(entries) instead of O(lineLength) and was written out - but it +is **not** a safe drop-in, because `collectFromBuffer` coalesces adjacent runs with +reference-equal styles and an entry walk does not. Without matching that, every overwrite +fragments the line a little more, and since `charAt` is O(entries), the result is a +permanently slower line in exchange for a one-off saving. That degradation would not show up +in a five-second benchmark; it would show up in a long session, which is the worst way to +find it. + +Doing it properly needs run coalescing across the splice boundaries, and that deserves its +own change rather than being tacked onto a latency pass. `TerminalLineWriteModelTest` is +committed as the harness for it: a randomised model check that pins what `writeString` must +produce, cell by cell, independently of how the line is stored. ### A fix that did not work, and why it looked like it would diff --git a/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionUtils.kt b/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionUtils.kt index 12df4b15c..ea603b71a 100644 --- a/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionUtils.kt +++ b/bossterm-core-mpp/src/jvmMain/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionUtils.kt @@ -116,6 +116,18 @@ object ColumnConversionUtils { fun visualColToBufferCol(line: TerminalLine, visualCol: Int, width: Int): Int { if (visualCol <= 0) return 0 + // A line that needs no visual-column mapping holds nothing above U+007F: no + // double-width characters, no DWC markers (U+E000), no combining marks, no + // surrogates. Every buffer column is therefore exactly one terminal cell, and the + // answer is the identity, clamped to the line. + // + // The scan below is O(visualCol) with an O(runs) `charAt` inside it, and + // `BossTerminal.wrapLines` calls it with the FULL terminal width every time a line + // wraps - which, for output whose lines exceed the window, is every line. Stack + // sampling the emulator thread through a sustained `cat` put ~10% of its time here, + // all of it from that one call site. + if (!line.requiresVisualColumnMapping) return minOf(visualCol, width) + var currentVisualCol = 0 var col = 0 diff --git a/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/model/TerminalLineWriteModelTest.kt b/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/model/TerminalLineWriteModelTest.kt new file mode 100644 index 000000000..316cf34fe --- /dev/null +++ b/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/model/TerminalLineWriteModelTest.kt @@ -0,0 +1,138 @@ +package ai.rever.bossterm.terminal.model + +import ai.rever.bossterm.terminal.TextStyle +import ai.rever.bossterm.terminal.util.CharUtils +import kotlin.random.Random +import kotlin.test.Test +import kotlin.test.assertEquals + +/** + * A model check on overlapping writes into a [TerminalLine]. + * + * `writeString` into the middle of a line goes through `merge`, which rebuilds the whole + * line into a char array plus a style array and then re-derives the style runs. Any faster + * path for that has to produce the identical line, and "identical" here means every cell's + * character and every cell's style - not a similar-looking entry list. + * + * This validates against an independent model (a plain char array and style array the test + * maintains itself) rather than against the previous implementation, so it pins the + * specification instead of the incumbent behaviour, and it keeps `TextEntries` private. + * + * Randomised with a fixed seed: the interesting cases are overlaps that start and end + * partway through an existing run, and enumerating those by hand reliably misses some. + */ +class TerminalLineWriteModelTest { + + private val styles = listOf( + TextStyle.EMPTY, + TextStyle(null, null, setOf(TextStyle.Option.BOLD)), + TextStyle(null, null, setOf(TextStyle.Option.ITALIC)), + TextStyle(null, null, setOf(TextStyle.Option.UNDERLINED)) + ) + + /** The line as the terminal should see it, maintained independently of TerminalLine. */ + private class Model { + val chars = ArrayList() + val styles = ArrayList() + + fun write(x: Int, text: String, style: TextStyle) { + // A gap is written as NUL, but TextEntries.add un-nullifies it as soon as any + // non-NUL entry lands after it, so it reads back as EMPTY_CHAR. Every case here + // writes text after the gap, so that conversion has always happened. + while (chars.size < x) { + chars.add(CharUtils.EMPTY_CHAR) + styles.add(TextStyle.EMPTY) + } + for (i in text.indices) { + val at = x + i + if (at < chars.size) { + chars[at] = text[i] + styles[at] = style + } else { + chars.add(text[i]) + styles.add(style) + } + } + } + } + + private fun assertMatches(line: TerminalLine, model: Model, note: String) { + assertEquals(model.chars.size, line.length(), "length differs after $note") + for (i in model.chars.indices) { + assertEquals(model.chars[i], line.charAt(i), "char at $i differs after $note") + assertEquals( + model.styles[i], + line.getStyleAt(i) ?: TextStyle.EMPTY, + "style at $i differs after $note" + ) + } + } + + @Test + fun overlappingWritesMatchTheModel() { + val random = Random(20260827) + repeat(200) { case -> + val line = TerminalLine() + val model = Model() + val ops = StringBuilder() + + repeat(6) { + val x = random.nextInt(0, 24) + val len = random.nextInt(1, 12) + val style = styles[random.nextInt(styles.size)] + val text = (0 until len).map { ('a' + random.nextInt(26)) }.joinToString("") + + ops.append("write($x, \"$text\") ") + line.writeString(x, CharBuffer(text), style) + model.write(x, text, style) + } + assertMatches(line, model, "case $case: $ops") + } + } + + @Test + fun aWriteStrictlyInsideAnExistingRunSplitsItCorrectly() { + // The case a faster merge is most likely to get wrong: the overwrite starts and + // ends partway through one run, so the run has to become head + new + tail. + val line = TerminalLine() + val model = Model() + line.writeString(0, CharBuffer("aaaaaaaaaa"), styles[0]) + model.write(0, "aaaaaaaaaa", styles[0]) + line.writeString(3, CharBuffer("XY"), styles[1]) + model.write(3, "XY", styles[1]) + assertMatches(line, model, "inner split") + } + + @Test + fun aWriteExtendingPastTheEndKeepsTheTail() { + val line = TerminalLine() + val model = Model() + line.writeString(0, CharBuffer("abcde"), styles[0]) + model.write(0, "abcde", styles[0]) + line.writeString(3, CharBuffer("ZZZZ"), styles[2]) + model.write(3, "ZZZZ", styles[2]) + assertMatches(line, model, "write past end") + } + + @Test + fun aWritePastTheEndFillsTheGap() { + val line = TerminalLine() + val model = Model() + line.writeString(0, CharBuffer("ab"), styles[0]) + model.write(0, "ab", styles[0]) + line.writeString(6, CharBuffer("Q"), styles[1]) + model.write(6, "Q", styles[1]) + assertMatches(line, model, "gap fill") + } + + @Test + fun awholeLineOverwriteReplacesEverything() { + val line = TerminalLine() + val model = Model() + line.writeString(0, CharBuffer("abcdef"), styles[0]) + model.write(0, "abcdef", styles[0]) + line.writeString(0, CharBuffer("ABCDEF"), styles[3]) + model.write(0, "ABCDEF", styles[3]) + assertMatches(line, model, "full overwrite") + } +} diff --git a/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionFastPathTest.kt b/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionFastPathTest.kt new file mode 100644 index 000000000..7dd5d946a --- /dev/null +++ b/bossterm-core-mpp/src/jvmTest/kotlin/ai/rever/bossterm/terminal/util/ColumnConversionFastPathTest.kt @@ -0,0 +1,83 @@ +package ai.rever.bossterm.terminal.util + +import ai.rever.bossterm.terminal.TextStyle +import ai.rever.bossterm.terminal.model.CharBuffer +import ai.rever.bossterm.terminal.model.TerminalLine +import kotlin.test.Test +import kotlin.test.assertEquals + +/** + * `visualColToBufferCol` short-circuits to the identity for lines that need no + * visual-column mapping. That is sound only because such a line holds nothing above + * U+007F: no double-width character, no DWC marker (U+E000), no combining mark, no + * surrogate. Every buffer column is then exactly one terminal cell. + * + * The guard is the whole correctness argument, so it is tested here rather than assumed. + * Without these, removing the guard entirely - taking the fast path for every line - passed + * the whole suite, which is exactly the silent breakage that matters: columns would be + * mapped as if wide characters were one cell wide, so selections, mouse hit-testing and + * line-wrap truncation would all land on the wrong cell whenever CJK or emoji is on screen. + */ +class ColumnConversionFastPathTest { + + private val style = TextStyle.EMPTY + + private fun asciiLine(text: String) = TerminalLine().apply { + writeString(0, CharBuffer(text), style) + } + + /** A line where each wide char occupies two cells: the char then a DWC marker. */ + private fun wideLine(): TerminalLine { + val sb = StringBuilder() + // "ab" then two double-width CJK characters, each followed by its DWC spacer. + sb.append("ab") + sb.append('你').append(CharUtils.DWC) + sb.append('好').append(CharUtils.DWC) + sb.append("cd") + return TerminalLine().apply { writeString(0, CharBuffer(sb.toString()), style) } + } + + @Test + fun plainAsciiMapsAsTheIdentity() { + val line = asciiLine("hello world") + val width = line.length() + for (v in 0..width) { + assertEquals(minOf(v, width), ColumnConversionUtils.visualColToBufferCol(line, v, width)) + } + } + + @Test + fun wideCharactersDoNotMapAsTheIdentity() { + // The assertion that kills a missing guard: visual column 4 sits inside the CJK + // run, whose buffer index is further along because each wide char carries a DWC + // spacer. If the fast path were taken here, this would come back as 4. + val line = wideLine() + val width = line.length() + + // buffer: 0=a 1=b 2=你 3=DWC 4=好 5=DWC 6=c 7=d + // visual: 0=a 1=b 2..3=你 4..5=好 6=c 7=d + // + // Most columns agree with the identity by coincidence. The ones that do NOT are the + // second cell of each wide character, where the visual column points into the glyph + // and the buffer index must snap back to its start - landing on the DWC marker + // instead is precisely what a missing guard would do. + assertEquals( + 2, ColumnConversionUtils.visualColToBufferCol(line, 3, width), + "visual col 3 is the second cell of the first wide char: it must snap back to " + + "buffer 2, not land on the DWC marker at buffer 3" + ) + assertEquals( + 4, ColumnConversionUtils.visualColToBufferCol(line, 5, width), + "visual col 5 is the second cell of the second wide char: it must snap back to " + + "buffer 4, not land on the DWC marker at buffer 5" + ) + } + + @Test + fun theGuardRejectsAWideLineAndAcceptsAnAsciiOne() { + // Direct check on the predicate the fast path keys off, so a change to how + // `requiresVisualColumnMapping` is maintained cannot silently widen the fast path. + assertEquals(false, asciiLine("plain ascii").requiresVisualColumnMapping) + assertEquals(true, wideLine().requiresVisualColumnMapping) + } +} From ef60bb9c595c3918f0fb83ab9016d980ab50b073 Mon Sep 17 00:00:00 2001 From: Shivang Date: Thu, 27 Aug 2026 14:17:13 -0400 Subject: [PATCH 10/10] fix: the debug panel gate read the collection flag, not the panel flag Regression from 610538b1, caught by the user on the first hand-check: pressing Cmd+Shift+D opened a permanently empty debug panel. TerminalTab carries two debug flags and they mean different things: debugEnabled background COLLECTION, seeded from settings.debugModeEnabled debugPanelVisible the UI, toggled with Cmd/Ctrl+Shift+D The gate read only debugEnabled. Opening the panel does not set that flag, so captureState kept skipping and the panel had nothing to render. Either flag means somebody wants the data, so either must capture. The predicate is now a pure function, shouldCaptureState(collectionEnabled, panelVisible), specifically so the mistake is testable rather than only findable by opening the panel. Restoring the old one-flag condition fails the new test. Worth naming the class of error: the two fields sit adjacent in the constructor with near-identical names, and their KDoc is what distinguishes them. I read the first, saw "debug", and did not check whether it was the one the keyboard shortcut writes. A gate on a feature nothing tests needs the flag traced to its writer, not matched by name. --- .../compose/debug/DebugDataCollector.kt | 24 +++++++++++++++---- .../debug/DebugDataCollectorTrimTest.kt | 23 ++++++++++++++++++ 2 files changed, 43 insertions(+), 4 deletions(-) diff --git a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt index 0ff560238..14aa6211e 100644 --- a/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt +++ b/compose-ui/src/desktopMain/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollector.kt @@ -95,6 +95,22 @@ class DebugDataCollector( writeChunkToFile(chunk) } + /** + * Whether a state snapshot is worth taking. + * + * TerminalTab carries TWO debug flags and they mean different things: + * + * - `debugEnabled` is background COLLECTION, seeded from `settings.debugModeEnabled`. + * - `debugPanelVisible` is the UI, toggled with Cmd/Ctrl+Shift+D. + * + * Either one means somebody wants the data, so either one must capture. Reading only + * the first is a real bug that shipped for one commit: pressing Cmd+Shift+D showed an + * empty panel, because opening the panel does not set the collection flag. It is a pure + * function so that mistake is testable rather than only visible by hand. + */ + internal fun shouldCaptureState(collectionEnabled: Boolean, panelVisible: Boolean): Boolean = + collectionEnabled || panelVisible + /** * Capture a snapshot of the current terminal state. * @@ -111,13 +127,13 @@ class DebugDataCollector( // // This is not a micro-optimisation. `createSnapshot()` is the FULL deep copy - every // line in the buffer, screen and history, cloned - and this runs on a timer every - // `debugCaptureInterval` (100 ms) for the life of every tab. With the debug panel - // off, which is the default (`debugModeEnabled = false`), all of it was thrown away. - // Profiling a 5 MB `cat` put 59% of samples in this call chain. + // `debugCaptureInterval` (100 ms) for the life of every tab. With debug off, which + // is the default, all of it was thrown away. Profiling a 5 MB `cat` put 59% of + // samples in this call chain. // // The loop keeps ticking rather than being torn down, because the panel can be // toggled at any time (Cmd/Ctrl+Shift+D) and must start showing data immediately. - if (!currentTab.debugEnabled.value) return + if (!shouldCaptureState(currentTab.debugEnabled.value, currentTab.debugPanelVisible.value)) return try { val textBuffer = currentTab.textBuffer diff --git a/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt index 6ba83defe..19d65b216 100644 --- a/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt +++ b/compose-ui/src/desktopTest/kotlin/ai/rever/bossterm/compose/debug/DebugDataCollectorTrimTest.kt @@ -2,6 +2,7 @@ package ai.rever.bossterm.compose.debug import kotlin.test.Test import kotlin.test.assertEquals +import kotlin.test.assertFalse import kotlin.test.assertTrue /** @@ -60,4 +61,26 @@ class DebugDataCollectorTrimTest { assertEquals(30, collector.getChunkCount()) assertTrue(collector.getDebugChunks().first().data.concatToString() == "c-0") } + + @Test + fun snapshotsAreCapturedWheneverEitherDebugFlagIsSet() { + // This is a REGRESSION TEST for a bug that shipped. TerminalTab has two debug + // flags: `debugEnabled` (background collection, from settings) and + // `debugPanelVisible` (the UI, toggled with Cmd/Ctrl+Shift+D). The gate originally + // read only the first, so pressing Cmd+Shift+D opened a permanently empty panel - + // opening the panel does not set the collection flag. + val collector = DebugDataCollector(tab = null, maxChunks = 8, maxSnapshots = 4) + + // The case that was broken: panel open, collection flag untouched. + assertTrue( + collector.shouldCaptureState(collectionEnabled = false, panelVisible = true), + "opening the debug panel must start capturing, or the panel renders empty" + ) + // Background collection with the panel closed is the other real configuration. + assertTrue(collector.shouldCaptureState(collectionEnabled = true, panelVisible = false)) + assertTrue(collector.shouldCaptureState(collectionEnabled = true, panelVisible = true)) + + // And the default, which is the whole point of the gate: no deep copy per tick. + assertFalse(collector.shouldCaptureState(collectionEnabled = false, panelVisible = false)) + } }