diff --git a/docs/USAGE.md b/docs/USAGE.md index 15cc2b28..9cbb14fb 100644 --- a/docs/USAGE.md +++ b/docs/USAGE.md @@ -296,7 +296,7 @@ agent-tty record export --format webm --json | jq -c '.result.missi # [{"codePoint":"U+0378"}] ``` -WebM export replays with recorded wall-clock timing by default. Pass `--timing accelerated` (idle gaps clamped to 400ms) or `--timing max-speed` for a time-compressed video. +WebM export replays with recorded wall-clock timing by default. Pass `--timing accelerated` (idle gaps clamped to 400ms) or `--timing max-speed` for a time-compressed video. A frame of the video shows the screen after the output that arrived within one frame hold of the first output of that frame: 16 ms in `recorded` and `max-speed` mode, 100 ms in `accelerated` mode. Output events that close together share one frame, so a burst of output does not cost one frame per event, and a state that the next output of the frame replaces is not shown. In `recorded` and `accelerated` mode, an event that changes no pixel (an input, a marker, a run-complete, a signal or the exit) also ends a frame. In `max-speed` mode it does not: only recorded time ends a frame, so output on both sides of an input event that is less than 16 ms apart shares one frame. `max-speed` removes the idle time. It makes a frame at most once per 16 ms of recorded time, so a progress bar that updates every 30 ms shows many of its steps and not only its last one. It makes at most about 2,400 frames, so a recording longer than 38 s gets one frame per 1/2,400 of its recorded time instead (a 1-hour recording: one per 1.5 s), and its export time depends on its length and not on its number of events. `max-speed` waits for one animation frame after each frame but holds no further time between two frames, so two frames that follow each other can end up in one video frame. The video has 25 frames per second, so it can skip a state that lasts less than one video frame (40 ms). A step of 30 ms is shorter than that, and the number of steps that survive depends on how fast the host runs the export. SVG export renders styled grid frames from the event log through the native `libghostty-vt` backend with no browser and no ffmpeg, so it requires the optional `@coder/libghostty-vt-node` package (there is no `ghostty-web` fallback). The output is deterministic: exporting the same session twice produces byte-identical, diffable SVG. `--format svg` writes a still image of the final screen and ignores event timing, so it also works on a log whose clock stepped backward (`--animate` refuses such a log and names the event where the clock stepped back); add `--animate` for an animated SVG of de-duplicated frames replayed with recorded event-log timing (`--timing` is not supported with SVG). diff --git a/src/export/README.md b/src/export/README.md index 876ffdfa..5a471594 100644 --- a/src/export/README.md +++ b/src/export/README.md @@ -25,7 +25,7 @@ This directory converts a session's event log into recording exports. `generateA - Defaults: timing mode `recorded` and profile `reference-dark` [webm.ts:generateWebmExport]. - A requested `libghostty-vt` renderer is replaced with `ghostty-web`. A code comment says `libghostty-vt` is semantic-only [webm.ts:generateWebmExport]. - The default backend factory accepts only `ghostty-web` [webm.ts:createDefaultBackend]. -- Timing presets: `accelerated` caps gaps at 400 ms and holds frames at least 100 ms. `max-speed` holds frames at least 16 ms. Each mode holds the final frame (1000 ms, or 500 ms for `max-speed`) [webm.ts:buildReplayTimingOptions]. +- Timing presets: `accelerated` caps gaps at 400 ms and holds frames at least 100 ms. `max-speed` uses a frame hold of 16 ms, but holds it only after the last flush of the replay and before and after a resize (see the `ghostty-web` README). Each mode holds the final frame (1000 ms, or 500 ms for `max-speed`) [webm.ts:buildReplayTimingOptions]. - The timed replay fails after `REPLAY_TIMEOUT_MS` (5 minutes) [webm.ts:REPLAY_TIMEOUT_MS]. - `renderGridFramesToSvg` needs the profile font size `SVG_FONT_SIZE` (14) and draws fixed 8.4x18 px cells, so equal input gives byte-identical output [svg.ts:renderGridFramesToSvg]. It always embeds the JetBrains Mono subset, and embeds each other bundled face only when a glyph needs it [svg.ts:embeddedFontAssets]. Output past `defaultMaxSvgOutputLength` of the V8 heap limit (the heap limit divided by 8 bytes, at most `MAX_SVG_OUTPUT_LENGTH`) fails with `EXPORT_ERROR` [svg.ts:defaultMaxSvgOutputLength]. diff --git a/src/renderer/ghosttyWeb/README.md b/src/renderer/ghosttyWeb/README.md index 10ea8ac4..8abfa834 100644 --- a/src/renderer/ghosttyWeb/README.md +++ b/src/renderer/ghosttyWeb/README.md @@ -20,7 +20,7 @@ This directory holds the `ghostty-web` reference renderer. `GhosttyWebBackend` s - `stripTrailingAsciiSpaces(text)` and `assembleCanonicalLine(cols, readColumn)` build canonical line text [harnessDecoding.ts:assembleCanonicalLine]. - Assertion helpers `assertNonNegativeInteger`, `assertPositiveInteger`, `assertPositiveNumber` and `assertHexColor`, plus `normalizeError(error, prefix)` [harnessDecoding.ts:normalizeError]. - `loadHarnessHtml()` returns `EMBEDDED_HARNESS_HTML` [harnessDecoding.ts:loadHarnessHtml]. -- `EMBEDDED_HARNESS_HTML` is the harness page as a template string. In the browser it defines `window.__agentTty` with `write`, `getSnapshot`, `getCellGraphemes`, `getVisibleText`, `isReady`, `resize` and `setCursorVisible` [embeddedHarnessHtml.ts:EMBEDDED_HARNESS_HTML]. +- `EMBEDDED_HARNESS_HTML` is the harness page as a template string. In the browser it defines `window.__agentTty` with `write`, `writeBatch`, `discardHeldChunks`, `notePaintedGraphemes`, `getSnapshot`, `getCellGraphemes`, `getVisibleText`, `isReady`, `resize` and `setCursorVisible` [embeddedHarnessHtml.ts:EMBEDDED_HARNESS_HTML]. - `harness.html` is a standalone copy of the harness page. No code serves it, and it differs from `EMBEDDED_HARNESS_HTML` [harnessDecoding.ts:loadHarnessHtml]. - `assets/` (not documented separately): holds the bundled fonts `JetBrainsMono-Regular-latin.woff2`, `SymbolsNerdFontMono-Regular.ttf`, `NotoSansSymbols2-Regular.woff2` and `NotoSansMath-Regular.woff2`, plus `FONT-LICENSE.txt` and the OFL texts of the Noto fonts. `scripts/subset-symbol-fonts.sh` rebuilds the two Noto subsets. `src/renderer/bundledFont.ts` loads them, and `scripts/copy-renderer-assets.mjs` copies them into `dist/` during `npm run build`. @@ -29,7 +29,8 @@ This directory holds the `ghostty-web` reference renderer. `GhosttyWebBackend` s - The constructor asserts a non-empty `sessionId`, `profile.name` and `profile.fontFamily`, a positive `fontSize`, and hex colors. With `videoOptions`, `outputDir` must be absolute and the size must use positive integers [backend.ts:GhosttyWebBackend.constructor]. - Replay cannot rewind: `targetSeq` must be >= the last applied seq. The initial dimensions cannot change after the first replay. `input.sessionId` must match the backend [backend.ts:GhosttyWebBackend.replayTo]. - `replayWithTiming` asserts strictly increasing seqs and non-decreasing timestamps [backend.ts:GhosttyWebBackend.replayWithTiming]. -- `replayWithTiming` waits until each event's place on a schedule built from the recorded gaps: `recorded` keeps them, `accelerated` caps each at `maxGapMs`, and `max-speed` sets them to 0. It measures that schedule with `performance.now()`, so frame holds and bridge calls use up idle time instead of adding to it. In `recorded` and `accelerated` mode it flushes pending output once the next event is at least one frame hold after the batch's first output, unless the replay runs behind the schedule, in which case the batch grows until it catches up. `max-speed` flushes once per run of output events [backend.ts:GhosttyWebBackend.replayWithTiming]. +- `replayWithTiming` waits until each event's place on a schedule built from the recorded gaps: `recorded` keeps them, `accelerated` caps each at `maxGapMs`, and `max-speed` sets them to 0. It measures that schedule with `performance.now()`, so frame holds and bridge calls use up idle time instead of adding to it. In `recorded` and `accelerated` mode it flushes pending output once the next event is at least one frame hold after the batch's first output, unless the replay runs behind the schedule, in which case the batch grows until it catches up. `max-speed` has no schedule to fall behind, so only recorded time ends its flushes. A flush ends at the first event that is at least one frame hold of recorded time after the batch's first output. An event that changes no pixel does not end it: input, marker, run-complete, signal and exit events leave the batch as it is, because a flush at each of them would cost a frame per event. A resize and the end of the replay still end it. `max-speed` also spreads at most `MAX_SPEED_FRAME_BUDGET` (2,400) flushes over the recorded span of the events that it applies: the distance between the first output of a flush and the event that ends it is at least the larger of the frame hold and the span divided by 2,400. So a `max-speed` replay makes about one flush per frame hold of recorded time for a recording shorter than 38 s and at most about 2,400 flushes for a longer one, whatever its number of events. Output that arrives less than that distance after the first output of a flush shares the flush, also when an input or a marker sits between, so a state that the next output of the flush replaces is never painted. A flush waits for one animation frame. `max-speed` holds the frame hold only after the last flush of the replay and before and after a resize, so two flushes that follow each other can paint within one video frame. In `recorded` and `accelerated` mode, every event that changes no pixel ends a flush, and a hold follows every flush. Events with the same timestamp share a flush at any hold, 0 included, because a flush needs at least 1 ms of recorded time [backend.ts:GhosttyWebBackend.replayWithTiming]. +- `writeBatch(chunks, endsFlush, paintedCap)` takes the chunks of one bridge call. A flush that has more than 1000 chunks needs several calls, and ghostty-web paints on every animation frame, so the page holds the chunks of a call that does not end the flush. The call that ends it (`endsFlush`, set by the backend on the last call only) writes every held chunk in one task, so no frame paints a state between two calls, and then resolves after one frame. ghostty-web calls a write callback one animation frame (about 17 ms) after the write, and waiting on every chunk (`write`) cost one frame per output event. `write()` and `resize()` throw while chunks are held. `discardHeldChunks()` drops them: the backend calls it when a flush fails, because `HostRendererManager` keeps the backend and a retry would otherwise meet them. A `paintedCap` that is not null makes the call that ends the flush add the graphemes on the screen to the set that the missing-glyph check of `replayWithTiming` probes, so a flush is one page call. The call returns the message of a failed note and not an error, because a failed note must not fail the flush. In `replayWithTiming`, the chunks of one flush share one video frame [embeddedHarnessHtml.ts:EMBEDDED_HARNESS_HTML]. - `snapshot()` and `screenshot()` throw until `replayTo()` or `replayWithTiming()` has run once and set the initial size. Both replays accept `targetSeq` -1 for an empty Event Log. A replay over zero events sets `lastAppliedSeq` to `targetSeq` [backend.ts:GhosttyWebBackend.snapshot]. - `missingGlyphs` lists a code point only when a bundled face that lacks it drew it. Chromium draws a cluster with one font: the first stack font that covers all of it, or else the first font of the stack, which is bundled in both built-in profiles and then draws `.notdef` boxes. CDP names the face that drew a probe by its PostScript name, so a family alias or several faces under one family resolve to the right cmap. When one bundled face drew the whole grapheme, every code point that face lacks is listed. A probe with no reported font is judged against every face of the first family. When the grapheme is split over several fonts, each uncovered code point is judged by its own probe, and a mark's probe on its base is compared with a probe of the base alone. Glyphs that a host font draws are not listed. The check runs after the PNG is written, removes its probe spans, and caches each probe text's result for the page, clearing the cache when it would pass `MAX_CACHED_GLYPH_PROBES` (16384) entries. It probes at most `MAX_GLYPH_PROBES` texts and lists at most `MAX_MISSING_GLYPH_CELLS` cells (4096 each). `probeUsedFonts` sends its CDP queries in batches of 256 and stops starting batches after `GLYPH_PROBE_BUDGET_MS` (1000 ms). The result sets `missingGlyphsTruncated` when any of these stops the check early. Family names match without regard to case. A web font whose PostScript name the profile does not bundle fails the check. A failed check is logged at debug level and leaves the field out, so the screenshot still succeeds. `replayWithTiming()` records the viewport graphemes in the page after each output batch and each resize (at most `MAX_CACHED_GLYPH_PROBES`), and the final frame hold judges them once, with the hold as the probe budget, so the check does not lengthen the video. `recordedMissingGlyphs()` returns that result. A failed note or check leaves the record export fields out. A profile whose font stack does not start with a bundled font gets no `missingGlyphs` field [missingGlyphs.ts:probeUsedFonts] [backend.ts:GhosttyWebBackend.screenshot]. - `screenshot()` requires an absolute `outputPath` whose parent directory exists. It checks that the output is a non-empty PNG with a valid signature and an `IHDR` first chunk [backend.ts:GhosttyWebBackend.screenshot]. @@ -49,7 +50,7 @@ This directory holds the `ghostty-web` reference renderer. `GhosttyWebBackend` s - Reads the `ghostty-web` package files (`ghostty-web.js`, its browser-external helper and `ghostty-vt.wasm`) with `fs/promises` once per process [backend.ts:getServedAssets]. - Starts a `node:http` server on `127.0.0.1` with an ephemeral port. It serves the harness, the `ghostty-web` assets and the bundled fonts for `GET` and `HEAD` [backend.ts:GhosttyWebBackend.startServer]. - Calls `ensurePlaywrightBrowsersPath()`, which can set `process.env.PLAYWRIGHT_BROWSERS_PATH`. Then it launches headless Chromium with `chromium.launch` [backend.ts:GhosttyWebBackend.bootInternal]. -- Calls `page.evaluate` on `window.__agentTty` to write output, resize and read snapshots [backend.ts:GhosttyWebBackend.writeBatchBridge]. +- Calls `page.evaluate` on `window.__agentTty` to write output, resize and read snapshots. One `writeBatch` call carries up to 1000 output chunks, and the page holds them until the last call of the flush [backend.ts:GhosttyWebBackend.writeBatchBridge]. - `screenshot()` writes the PNG through Playwright `locator('#terminal').screenshot`, then reads it back to hash it [backend.ts:GhosttyWebBackend.screenshot]. - With `videoOptions`, Playwright records into `outputDir`. `finalizeVideo()` closes the page and context and calls `video.saveAs(outputPath)` [backend.ts:GhosttyWebBackend.finalizeVideo]. - `dispose()` closes the page, context, browser and HTTP server [backend.ts:GhosttyWebBackend.dispose]. diff --git a/src/renderer/ghosttyWeb/backend.ts b/src/renderer/ghosttyWeb/backend.ts index 0aecf144..8fab2484 100644 --- a/src/renderer/ghosttyWeb/backend.ts +++ b/src/renderer/ghosttyWeb/backend.ts @@ -81,6 +81,13 @@ interface GhosttyServedAsset extends GhosttyRequestAsset { interface GhosttyBrowserBridge { isReady?: () => boolean; write?: (data: string) => Promise | void; + writeBatch?: ( + chunks: string[], + endsFlush?: boolean, + paintedCap?: number | null, + ) => Promise | string | null; + discardHeldChunks?: () => void; + notePaintedGraphemes?: (cap: number) => void; resize?: (cols: number, rows: number) => Promise | void; setCursorVisible?: (visible: boolean) => Promise | void; getSnapshot?: (options?: SnapshotOptions) => GhosttyHarnessSnapshot; @@ -130,12 +137,43 @@ const HTML_CONTENT_TYPE = 'text/html; charset=utf-8'; const WASM_CONTENT_TYPE = 'application/wasm'; const MAX_REPLAY_BATCH_SIZE = 1000; +/** + * A max-speed replay makes at most about this many flushes, however long the + * recording is. A flush costs one animation frame, one page call and one scan + * of the screen: 26 ms at 80x24, 33 ms at 120x40 and 112 ms at 200x60 in the + * median of five sparse-log runs (host load 40 to 100). The limit then takes + * 1 to 4.5 minutes, under the 5 minutes that a WebM export allows its replay. + * The video has 25 frames per second, so this many flushes fill 96 s of video. + */ +const MAX_SPEED_FRAME_BUDGET = 2_400; const RAF_TIMEOUT_MS = 5_000; let servedAssetsPromise: Promise< ReadonlyMap > | null = null; +/** + * Recorded time between the first and the last event that a replay applies: + * the seqs above `afterSeq`, up to the target. It is 0 when a timestamp does + * not parse. The replay loop rejects such a timestamp itself. + */ +function recordedSpanMs(input: ReplayInput, afterSeq: number): number { + let firstMs: number | undefined; + let lastMs = 0; + for (const event of input.events) { + if (event.seq <= afterSeq) { + continue; + } + if (event.seq > input.targetSeq) { + break; + } + lastMs = Date.parse(event.ts); + firstMs ??= lastMs; + } + const spanMs = lastMs - (firstMs ?? lastMs); + return Number.isFinite(spanMs) && spanMs > 0 ? spanMs : 0; +} + async function closeServer(server: Server): Promise { if (!server.listening) { return; @@ -648,6 +686,18 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { ); } + // Output shows once the next event is this far after the batch's first + // output. It is at least 1 ms: events with one timestamp share a flush. + // Max-speed has no schedule that bounds its replay time, so it also + // spreads a fixed number of flushes over the recorded span: a sparse + // recording then costs the same number of frames as a dense one. + const minSplitMs = Math.max( + 1, + resolvedMinFrameHoldMs, + timing.mode === 'max-speed' + ? recordedSpanMs(input, this.lastAppliedSeq) / MAX_SPEED_FRAME_BUDGET + : 0, + ); let outputEventCount = 0; let previousEventSeq = -1; let previousProcessedEventTimestampMs: number | null = null; @@ -659,17 +709,28 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { let scheduleStartedAtMs = 0; let scheduledElapsedMs = 0; - const flushOutputBatch = async (): Promise => { + const flushOutputBatch = async (holdFrame = true): Promise => { if (pendingOutputChunks.length === 0) { return; } - await this.flushOutputBatch(page, pendingOutputChunks, () => - this.notePaintedGraphemes(page), - ); + await this.flushOutputBatch(page, pendingOutputChunks, undefined, true); pendingOutputChunks = []; pendingSinceTimestampMs = null; - await waitForDelay(resolvedMinFrameHoldMs); + if (holdFrame) { + await waitForDelay(resolvedMinFrameHoldMs); + } + }; + + // Events that change no pixel end a flush in recorded and accelerated + // mode, where the pause before them is part of the video. Max-speed has no + // pauses: a flush at each of them would cost one frame per event. So only + // recorded time ends a max-speed flush, and output on both sides of such + // an event shares a flush when it is less than one minimum split apart. + const flushBeforeNonVisualEvent = async (): Promise => { + if (timing.mode !== 'max-speed') { + await flushOutputBatch(); + } }; for (const event of input.events) { @@ -703,19 +764,22 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { 'replay event timestamps must be ordered non-decreasingly', ); scheduledElapsedMs += computeInterEventDelay(interEventDelayMs); - // Output shows once its batch is a frame hold old, unless the replay - // runs behind the schedule: then batches grow until it catches up, so - // slow flushes lower the frame rate instead of stretching the video. - // Max-speed keeps one batch per run of output events, so its frame - // holds cannot outlast the export timeout. + // Output shows once its batch is a minimum split old, unless the + // replay runs behind the schedule: then batches grow until it catches + // up, so slow flushes lower the frame rate instead of stretching the + // video. Max-speed has no schedule to fall behind. It flushes once per + // minimum split of recorded time at most, within the frame budget. + // The frame wait of such a flush is already its frame, so max-speed + // holds only after a flush that ends the replay or comes before a + // resize (a resize is followed by a hold too): a hold after every + // flush would export 30 ms steps slower than they ran. if ( - timing.mode !== 'max-speed' && pendingSinceTimestampMs !== null && - eventTimestampMs - pendingSinceTimestampMs >= - resolvedMinFrameHoldMs && - performance.now() - scheduleStartedAtMs <= scheduledElapsedMs + eventTimestampMs - pendingSinceTimestampMs >= minSplitMs && + (timing.mode === 'max-speed' || + performance.now() - scheduleStartedAtMs <= scheduledElapsedMs) ) { - await flushOutputBatch(); + await flushOutputBatch(timing.mode !== 'max-speed'); } // Waiting for the event's place on the schedule lets frame holds and // bridge calls use up time that the recording spent idle. @@ -756,7 +820,7 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { break; } case 'marker': { - await flushOutputBatch(); + await flushBeforeNonVisualEvent(); break; } case 'input_text': @@ -767,7 +831,7 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { case 'run_complete': case 'signal': case 'exit': { - await flushOutputBatch(); + await flushBeforeNonVisualEvent(); break; } default: { @@ -999,40 +1063,39 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { return; } await page.evaluate((cap) => { - const scope = globalThis as GhosttyBrowserGlobal; - const bridge = scope.__agentTty; + const bridge = (globalThis as GhosttyBrowserGlobal).__agentTty; if ( bridge === undefined || - typeof bridge.getCellGraphemes !== 'function' + typeof bridge.notePaintedGraphemes !== 'function' ) { throw new Error( - 'ghostty-web bridge getCellGraphemes() is unavailable', + 'ghostty-web bridge notePaintedGraphemes() is unavailable', ); } - scope.__agentTtyPainted ??= { seen: new Set(), complete: true }; - const painted = scope.__agentTtyPainted; - for (const row of bridge.getCellGraphemes()) { - for (const grapheme of row) { - if (grapheme === '' || painted.seen.has(grapheme)) { - continue; - } - if (painted.seen.size < cap) { - painted.seen.add(grapheme); - } else { - painted.complete = false; - } - } - } + bridge.notePaintedGraphemes(cap); }, MAX_CACHED_GLYPH_PROBES); } catch (error) { - this.paintedNoteFailed = true; - this.logger.debug( - 'Missing-glyph note failed; the record export result omits missingGlyphs', + this.failPaintedNote( error instanceof Error ? error.message : String(error), ); } } + private failPaintedNote(message: string): void { + this.paintedNoteFailed = true; + this.logger.debug( + 'Missing-glyph note failed; the record export result omits missingGlyphs', + message, + ); + } + + /** The cap that a flush passes to the page to note its painted graphemes. */ + private paintedNoteCap(): number | null { + return this.paintedNoteFailed || this.glyphCheck() === null + ? null + : MAX_CACHED_GLYPH_PROBES; + } + public async recordedMissingGlyphs(): Promise { return ( this.recordedGlyphs ?? this.checkPaintedGlyphs(GLYPH_PROBE_BUDGET_MS) @@ -1668,32 +1731,70 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { ]); } + /** + * Writes the chunks of one flush into the page. With `notePainted`, the page + * also notes the graphemes on the screen once the flush is written, in the + * call that ends the flush. + */ private async flushOutputBatch( page: Page, dataChunks: string[], afterEachBatch?: () => Promise, + notePainted = false, ): Promise { invariant( dataChunks.length > 0, 'flushOutputBatch requires at least one data chunk', ); - for ( - let batchStart = 0; - batchStart < dataChunks.length; - batchStart += MAX_REPLAY_BATCH_SIZE - ) { - const batch = dataChunks.slice( - batchStart, - batchStart + MAX_REPLAY_BATCH_SIZE, - ); - invariant(batch.length > 0, 'flushOutputBatch batch must not be empty'); - invariant( - batch.length <= MAX_REPLAY_BATCH_SIZE, - 'flushOutputBatch batch size must respect MAX_REPLAY_BATCH_SIZE', + try { + for ( + let batchStart = 0; + batchStart < dataChunks.length; + batchStart += MAX_REPLAY_BATCH_SIZE + ) { + const batch = dataChunks.slice( + batchStart, + batchStart + MAX_REPLAY_BATCH_SIZE, + ); + invariant(batch.length > 0, 'flushOutputBatch batch must not be empty'); + invariant( + batch.length <= MAX_REPLAY_BATCH_SIZE, + 'flushOutputBatch batch size must respect MAX_REPLAY_BATCH_SIZE', + ); + // The page holds the batches of a flush until the last one. Then it + // writes them all and waits for one frame. + const endsFlush = + batchStart + MAX_REPLAY_BATCH_SIZE >= dataChunks.length; + await this.writeBatchBridge( + page, + batch, + endsFlush, + endsFlush && notePainted ? this.paintedNoteCap() : null, + ); + await afterEachBatch?.(); + } + } catch (error) { + // The page still holds the chunks of the calls that did succeed. The + // backend stays in use after a failed replay, and a retry would meet + // them: its output would follow them, and its resize would be refused. + await this.discardHeldChunks(page); + throw error; + } + } + + private async discardHeldChunks(page: Page): Promise { + try { + await page.evaluate(() => { + const bridge = (globalThis as GhosttyBrowserGlobal).__agentTty; + bridge?.discardHeldChunks?.(); + }); + } catch (error) { + // A page that fails here is as broken as the call that failed first. + this.logger.debug( + 'Dropping the held chunks of a failed flush failed', + error instanceof Error ? error.message : String(error), ); - await this.writeBatchBridge(page, batch); - await afterEachBatch?.(); } } @@ -1777,6 +1878,8 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { private async writeBatchBridge( page: Page, dataChunks: string[], + endsFlush = true, + paintedCap: number | null = null, ): Promise { invariant( dataChunks.length > 0, @@ -1790,16 +1893,26 @@ export class GhosttyWebBackend implements VideoCapableRendererBackend { assertString(chunk, 'bridge batch write chunk must be a string'); } - await page.evaluate(async (chunks: string[]) => { - const bridge = (globalThis as GhosttyBrowserGlobal).__agentTty; - if (bridge === undefined || typeof bridge.write !== 'function') { - throw new Error('ghostty-web bridge write() is unavailable'); - } + const noteError = await page.evaluate( + async ([chunks, batchEndsFlush, batchPaintedCap]: readonly [ + string[], + boolean, + number | null, + ]) => { + const bridge = (globalThis as GhosttyBrowserGlobal).__agentTty; + if (bridge === undefined || typeof bridge.writeBatch !== 'function') { + throw new Error('ghostty-web bridge writeBatch() is unavailable'); + } - for (const chunk of chunks) { - await bridge.write(chunk); - } - }, dataChunks); + return await bridge.writeBatch(chunks, batchEndsFlush, batchPaintedCap); + }, + [dataChunks, endsFlush, paintedCap] as const, + ); + // The page notes the painted graphemes in this call and reports a failed + // note by its message, so that the note cannot fail the flush. + if (typeof noteError === 'string') { + this.failPaintedNote(noteError); + } } private async writeBridge(page: Page, data: string): Promise { diff --git a/src/renderer/ghosttyWeb/embeddedHarnessHtml.ts b/src/renderer/ghosttyWeb/embeddedHarnessHtml.ts index 6ed36c1b..666368d2 100644 --- a/src/renderer/ghosttyWeb/embeddedHarnessHtml.ts +++ b/src/renderer/ghosttyWeb/embeddedHarnessHtml.ts @@ -262,6 +262,8 @@ export const EMBEDDED_HARNESS_HTML = ` const state = { errorMessage: null, + // Chunks of a flush that writeBatch() holds until the call that ends it. + heldChunks: [], ready: false, terminal: null, }; @@ -570,6 +572,29 @@ export const EMBEDDED_HARNESS_HTML = ` return grid; } + // Adds the graphemes on the screen to the set that the missing-glyph + // check of a recorded replay probes. The cap bounds the set. + function notePaintedGraphemes(cap) { + assertPositiveInteger( + cap, + 'notePaintedGraphemes() cap must be a positive integer', + ); + window.__agentTtyPainted ??= { seen: new Set(), complete: true }; + const painted = window.__agentTtyPainted; + for (const row of getCellGraphemes()) { + for (const grapheme of row) { + if (grapheme === '' || painted.seen.has(grapheme)) { + continue; + } + if (painted.seen.size < cap) { + painted.seen.add(grapheme); + } else { + painted.complete = false; + } + } + } + } + function getSnapshotPayload(options) { invariant( options === undefined || @@ -645,12 +670,83 @@ export const EMBEDDED_HARNESS_HTML = ` async write(data) { const terminal = getReadyTerminal(); assertStringValue(data, 'write() data must be a string'); + invariant( + state.heldChunks.length === 0, + 'write() cannot run while writeBatch() holds the chunks of a flush', + ); await new Promise((resolve) => { terminal.write(data, resolve); }); updateDocumentState(); }, + async writeBatch(chunks, endsFlush = true, paintedCap = null) { + const terminal = getReadyTerminal(); + invariant( + Array.isArray(chunks) && chunks.length > 0, + 'writeBatch() chunks must be a non-empty array', + ); + invariant( + typeof endsFlush === 'boolean', + 'writeBatch() endsFlush must be a boolean', + ); + invariant( + paintedCap === null || Number.isInteger(paintedCap), + 'writeBatch() paintedCap must be null or an integer', + ); + for (const chunk of chunks) { + assertStringValue(chunk, 'writeBatch() chunks must be strings'); + } + + // A flush shows as one frame. A flush that needs several calls holds + // its chunks here until the call that ends it, so no frame paints + // the screen between two calls: ghostty-web renders on every animation + // frame, and a video records every paint. The call that ends the + // flush writes all chunks in one task. The wasm write is synchronous, + // but ghostty-web calls a write callback one animation frame later, + // so waiting on every chunk made a replay cost one frame per event. + // The callback on the last chunk makes the call resolve after a frame. + for (const chunk of chunks) { + state.heldChunks.push(chunk); + } + if (!endsFlush) { + return null; + } + + const flush = state.heldChunks; + state.heldChunks = []; + const lastIndex = flush.length - 1; + for (let index = 0; index < lastIndex; index += 1) { + terminal.write(flush[index]); + } + await new Promise((resolve) => { + terminal.write(flush[lastIndex], resolve); + }); + updateDocumentState(); + + // The caller asks to note the painted graphemes of a recorded + // replay here, so a flush costs one page call and not two. A failed + // note must not fail the flush: the call returns its message, and + // the caller then drops the missing-glyph fields of the export. + if (paintedCap === null) { + return null; + } + try { + notePaintedGraphemes(paintedCap); + return null; + } catch (error) { + return error instanceof Error ? error.message : String(error); + } + }, + // A flush that failed in the middle leaves its earlier calls' chunks + // held. The caller drops them, so that a retry starts from the screen + // as the failed flush found it. + discardHeldChunks() { + state.heldChunks = []; + }, + notePaintedGraphemes(cap) { + notePaintedGraphemes(cap); + }, getSnapshot(options) { return getSnapshotPayload(options); }, @@ -667,6 +763,10 @@ export const EMBEDDED_HARNESS_HTML = ` }, resize(cols, rows) { const terminal = getReadyTerminal(); + invariant( + state.heldChunks.length === 0, + 'resize() cannot run while writeBatch() holds the chunks of a flush', + ); assertPositiveInteger( cols, 'resize() cols must be a positive integer', diff --git a/test/integration/renderer-backend.test.ts b/test/integration/renderer-backend.test.ts index 5d357bf9..8a1ee507 100644 --- a/test/integration/renderer-backend.test.ts +++ b/test/integration/renderer-backend.test.ts @@ -1,3 +1,4 @@ +import { createHash } from 'node:crypto'; import { mkdtemp, readFile, realpath, rm, stat } from 'node:fs/promises'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; @@ -755,6 +756,430 @@ describe('GhosttyWebBackend integration', { timeout: 120_000 }, () => { } }); + // ghostty-web calls a write callback one animation frame (about 17 ms) + // after the write. A bridge call that waits on every chunk made a replay cost + // one frame per output event: 90 minutes for 250 000 events. + it.each([ + [ + 'replayTo', + (renderer: GhosttyWebBackend, input: ReplayInput) => + renderer.replayTo(input), + ], + [ + 'replayWithTiming', + (renderer: GhosttyWebBackend, input: ReplayInput) => + renderer.replayWithTiming(input, { + mode: 'max-speed', + minFrameHoldMs: 0, + finalFrameHoldMs: 0, + }), + ], + ])( + '%s waits for one animation frame per flush of output events, not per event', + async (_name, replay) => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + // ghostty-web calls a write callback one frame after the write, so the + // number of writes that pass a callback is the number of frames that a + // replay waits for. The string keeps vitest from rewriting the import. + await page.evaluate(`(async () => { + const { Terminal } = await import('/assets/ghostty-web.js'); + const write = Terminal.prototype.write; + globalThis.__writeFrameWaits = 0; + Terminal.prototype.write = function (data, callback) { + if (callback !== undefined) { + globalThis.__writeFrameWaits += 1; + } + return write.call(this, data, callback); + }; + })()`); + + // One character per event, so a chunk that is lost or moved changes + // the text on the screen. 2501 characters fill 32 rows of 80 columns. + const characters = Array.from({ length: 2_501 }, (_, seq) => + 'abcdefghijklmnopqrstuvwxyz0123456789'.charAt((seq * 7) % 36), + ); + const input = createReplayInput( + characters.map((character, seq) => ({ + seq, + ts: timestampFor(0), + type: 'output' as const, + payload: { data: character }, + })), + { initialRows: 40 }, + ); + await replay(backend, input); + + // A bridge call holds at most 1000 chunks, so 2501 events take 3 calls. + // Only the last call waits for a frame. + expect( + await page.evaluate( + () => + (globalThis as unknown as { __writeFrameWaits: number }) + .__writeFrameWaits, + ), + ).toBe(1); + const expectedRows = Array.from({ length: 32 }, (_, row) => + characters.slice(row * 80, (row + 1) * 80).join(''), + ); + const screenRows = (await backend.snapshot()).visibleLines.map( + (line) => line.text, + ); + expect(screenRows.slice(0, 32)).toEqual(expectedRows); + }, + ); + + // ghostty-web paints on every animation frame, and a WebM records every + // paint. A flush of more than 1000 chunks takes several page calls, so a + // state that exists between two calls can reach the video. + it.each([ + [ + 'replayTo', + (renderer: GhosttyWebBackend, input: ReplayInput) => + renderer.replayTo(input), + ], + [ + 'replayWithTiming', + (renderer: GhosttyWebBackend, input: ReplayInput) => + renderer.replayWithTiming(input, { + mode: 'max-speed', + minFrameHoldMs: 16, + finalFrameHoldMs: 200, + }), + ], + ])( + '%s paints a flush of several page calls as one frame', + async (_name, replay) => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + // The screencast is the source of the frames that Playwright encodes into + // a video: it sends a frame for every paint. + const screencast = await page.context().newCDPSession(page); + const frames: string[] = []; + screencast.on('Page.screencastFrame', (frame) => { + const hash = createHash('sha256').update(frame.data).digest('hex'); + if (frames.at(-1) !== hash) { + frames.push(hash); + } + void screencast + .send('Page.screencastFrameAck', { sessionId: frame.sessionId }) + .catch(() => {}); + }); + await screencast.send('Page.startScreencast', { + format: 'png', + everyNthFrame: 1, + }); + + // Each bridge call of 1000 chunks fills the screen with its own colour + // (red, green, blue), so a paint between two calls shows a colour that is + // not the last. A pause after each call stands for a slow host. + const backgroundFor = (seq: number): number => + [41, 42, 44][Math.floor(seq / 1_000)] ?? 44; + const input = createReplayInput( + Array.from({ length: 2_501 }, (_, seq) => ({ + seq, + ts: timestampFor(0), + type: 'output' as const, + payload: { data: `\u001b[${String(backgroundFor(seq))}m\u001b[2J` }, + })), + ); + const writeBatchBridge = ( + backend as unknown as { + writeBatchBridge: (...args: unknown[]) => Promise; + } + ).writeBatchBridge.bind(backend); + Object.assign(backend as object, { + writeBatchBridge: async (...args: unknown[]) => { + await writeBatchBridge(...args); + await new Promise((resolve) => setTimeout(resolve, 100)); + }, + }); + // Wait until the screen before the replay is quiet: a slow host can + // deliver a late paint of the first screen, which is not a frame of the + // replay. The screen before the replay counts as one frame. + let framesSeen = 0; + let quietSinceMs = Date.now(); + await expect + .poll( + () => { + if (frames.length !== framesSeen) { + framesSeen = frames.length; + quietSinceMs = Date.now(); + } + return framesSeen > 0 && Date.now() - quietSinceMs >= 300; + }, + { timeout: 10_000 }, + ) + .toBe(true); + const framesBefore = frames.length; + await replay(backend, input); + // The last colour must reach the listener. Then wait a little more, so + // that a frame between two calls would have arrived too. + await expect + .poll(() => frames.length, { timeout: 10_000 }) + .toBeGreaterThan(framesBefore); + await new Promise((resolve) => setTimeout(resolve, 500)); + await screencast.send('Page.stopScreencast'); + + // The screen before the replay, then the frame of the last colour. + expect(frames).toHaveLength(framesBefore + 1); + }, + ); + + it('holds the chunks of a flush until the call that ends it', async () => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + const visibleFirstRow = (): Promise => + page.evaluate( + `window.__agentTty.getVisibleText().split('\\n')[0]`, + ) as Promise; + await page.evaluate('window.__agentTty.resize(80, 24)'); + + await page.evaluate(`window.__agentTty.writeBatch(['ab'], false)`); + await page.evaluate(`window.__agentTty.writeBatch(['cd'], false)`); + expect(await visibleFirstRow()).toBe(''); + + // A direct write or a resize would move the held chunks behind its own + // output, so the page refuses both. + await expect(page.evaluate(`window.__agentTty.write('x')`)).rejects.toThrow( + 'holds the chunks of a flush', + ); + await expect( + page.evaluate(`window.__agentTty.resize(100, 30)`), + ).rejects.toThrow('holds the chunks of a flush'); + expect(await visibleFirstRow()).toBe(''); + + await page.evaluate(`window.__agentTty.writeBatch(['ef'], true)`); + expect(await visibleFirstRow()).toBe('abcdef'); + }); + + // HostRendererManager keeps the backend after a failed replay and retries + // from the same seq. The page held the chunks of the calls before the one + // that failed, so a retry that started with a resize was refused for good. + it('runs a retry that starts with a resize after a page call failed in the middle of a flush', async () => { + await backend.boot(); + // One character per event, so a chunk that is lost, repeated or moved + // changes the text on the screen. 2501 characters fill 32 rows of 80 + // columns. + const characters = Array.from({ length: 2_501 }, (_, index) => + 'abcdefghijklmnopqrstuvwxyz0123456789'.charAt((index * 7) % 36), + ); + const outputs = (firstSeq: number): ReplayInput['events'] => + characters.map((character, index) => ({ + seq: firstSeq + index, + ts: timestampFor(0), + type: 'output' as const, + payload: { data: character }, + })); + const writeBatchBridge = ( + backend as unknown as { + writeBatchBridge: (...args: unknown[]) => Promise; + } + ).writeBatchBridge.bind(backend); + let pageCalls = 0; + Object.assign(backend as object, { + writeBatchBridge: async (...args: unknown[]) => { + pageCalls += 1; + if (pageCalls === 2) { + throw new Error('page call failed'); + } + await writeBatchBridge(...args); + }, + }); + + await expect( + backend.replayTo(createReplayInput(outputs(0))), + ).rejects.toThrow('page call failed'); + + Object.assign(backend as object, { writeBatchBridge }); + await backend.replayTo( + createReplayInput( + [ + { + seq: 0, + ts: timestampFor(0), + type: 'resize', + payload: { cols: 80, rows: 40 }, + }, + ...outputs(1), + ], + { initialRows: 24 }, + ), + ); + + const expectedRows = Array.from({ length: 32 }, (_, row) => + characters.slice(row * 80, (row + 1) * 80).join(''), + ); + const screenRows = (await backend.snapshot()).visibleLines.map( + (line) => line.text, + ); + expect(screenRows.slice(0, 32)).toEqual(expectedRows); + }); + + // A flush of 1001 chunks takes two page calls, and the glyph that it paints + // comes with its last chunk. The next flush erases it. + it('records the glyphs that a flush painted, in the page call that ends the flush', async () => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + const pageFunctions: string[] = []; + const evaluate = page.evaluate.bind(page) as ( + ...args: unknown[] + ) => Promise; + Object.assign(page, { + evaluate: (pageFunction: unknown, ...rest: unknown[]) => { + pageFunctions.push(String(pageFunction)); + return evaluate(pageFunction, ...rest); + }, + }); + + await backend.replayWithTiming( + createReplayInput([ + ...Array.from({ length: 1_000 }, (_, seq) => ({ + seq, + ts: timestampFor(0), + type: 'output' as const, + payload: { data: 'x' }, + })), + { + seq: 1_000, + ts: timestampFor(0), + type: 'output' as const, + payload: { data: '\u0378' }, + }, + { + seq: 1_001, + ts: timestampFor(1), + type: 'output' as const, + payload: { data: '\u001b[2J\u001b[Hok' }, + }, + ]), + { mode: 'max-speed', minFrameHoldMs: 16, finalFrameHoldMs: 200 }, + ); + + await expect(backend.recordedMissingGlyphs()).resolves.toEqual({ + missingGlyphs: [{ codePoint: 'U+0378' }], + }); + // 1001 chunks take 2 calls, the next flush takes 1. None of them has a + // call of its own for the note. + expect( + pageFunctions.filter((source) => source.includes('writeBatch')), + ).toHaveLength(3); + expect( + pageFunctions.filter((source) => source.includes('notePaintedGraphemes')), + ).toHaveLength(0); + }); + + it('writes a flush even when its painted-grapheme note fails, and reports the failure', async () => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + await page.evaluate('window.__agentTty.resize(80, 24)'); + + // A cap of 0 makes the note throw after the chunks are on the screen. + const noteError = await page.evaluate( + `window.__agentTty.writeBatch(['ab', 'cd'], true, 0)`, + ); + + expect(noteError).toEqual( + expect.stringContaining('cap must be a positive integer'), + ); + expect( + await page.evaluate(`window.__agentTty.getVisibleText().split('\\n')[0]`), + ).toBe('abcd'); + }); + + // A resize can bring graphemes on the screen that no flush showed: growing + // the screen pulls lines back from the scrollback. The note that follows the + // resize records them, and the next flush then erases the screen. + it('records a glyph that a resize brings back from the scrollback', async () => { + await backend.boot(); + + await backend.replayWithTiming( + createReplayInput([ + { + seq: 0, + ts: timestampFor(0), + type: 'output', + payload: { + data: `\u0378\r\n${Array.from({ length: 30 }, (_, line) => `line ${String(line)}\r\n`).join('')}`, + }, + }, + { + seq: 1, + ts: timestampFor(1), + type: 'resize', + payload: { cols: 80, rows: 40 }, + }, + { + seq: 2, + ts: timestampFor(2), + type: 'output', + payload: { data: '\u001b[2J\u001b[Hok' }, + }, + ]), + { mode: 'max-speed', minFrameHoldMs: 16, finalFrameHoldMs: 200 }, + ); + + await expect(backend.recordedMissingGlyphs()).resolves.toEqual({ + missingGlyphs: [{ codePoint: 'U+0378' }], + }); + }); + + // The page keeps the size attributes of the body (data-cols, data-rows) in + // step with the terminal after every write. The call that ends a flush does + // it too, as write() does. + it('refreshes the size attributes of the document when a flush ends', async () => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + await page.evaluate('window.__agentTty.resize(80, 24)'); + const sizeAttributes = (): Promise => + page.evaluate( + `document.body.dataset.cols + 'x' + document.body.dataset.rows`, + ) as Promise; + expect(await sizeAttributes()).toBe('80x24'); + await page.evaluate( + `document.body.dataset.cols = 'stale'; document.body.dataset.rows = 'stale'`, + ); + + await page.evaluate(`window.__agentTty.writeBatch(['ab'], false)`); + expect(await sizeAttributes()).toBe('stalexstale'); + await page.evaluate(`window.__agentTty.writeBatch(['cd'], true)`); + + expect(await sizeAttributes()).toBe('80x24'); + }); + + // The set of painted graphemes feeds a probe of every grapheme in it. The + // cap that the backend passes bounds the set, and a set that hit the cap is + // reported as incomplete, so the export result says that its list is cut. + it('bounds the painted graphemes by the cap of the call that ends a flush', async () => { + await backend.boot(); + const { page } = backend as unknown as { page: Page }; + await page.evaluate('window.__agentTty.resize(80, 24)'); + const painted = (): Promise<{ seen: string[]; complete: boolean } | null> => + page.evaluate( + `(() => { + const state = window.__agentTtyPainted; + return state === undefined ? null : { seen: [...state.seen], complete: state.complete }; + })()`, + ) as Promise<{ seen: string[]; complete: boolean } | null>; + + // Nothing is noted while the call does not ask for it. + await page.evaluate(`window.__agentTty.writeBatch(['abc'], true, null)`); + expect(await painted()).toBeNull(); + + await page.evaluate( + `window.__agentTty.writeBatch(['\\x1b[2J\\x1b[Habc'], true, 5)`, + ); + expect(await painted()).toEqual({ seen: ['a', 'b', 'c'], complete: true }); + + await page.evaluate( + `window.__agentTty.writeBatch(['\\x1b[2J\\x1b[Hdefgh'], true, 5)`, + ); + expect(await painted()).toEqual({ + seen: ['a', 'b', 'c', 'd', 'e'], + complete: false, + }); + }); + it('allows dispose to be called more than once', async () => { await backend.boot(); diff --git a/test/unit/renderer/ghosttyWebBackend.test.ts b/test/unit/renderer/ghosttyWebBackend.test.ts index 723b321f..9b37cdb5 100644 --- a/test/unit/renderer/ghosttyWebBackend.test.ts +++ b/test/unit/renderer/ghosttyWebBackend.test.ts @@ -16,6 +16,7 @@ import { afterEach, describe, expect, it, vi } from 'vitest'; import type { ReplayTimingOptions } from '../../../src/renderer/backend.js'; import type { ReplayInput } from '../../../src/renderer/types.js'; import { BUNDLED_FONT_ASSETS } from '../../../src/renderer/bundledFont.js'; +import { MAX_CACHED_GLYPH_PROBES } from '../../../src/renderer/ghosttyWeb/missingGlyphs.js'; import { hashProfile, resolveProfile } from '../../../src/renderer/profiles.js'; import { GhosttyWebBackend } from '../../../src/renderer/ghosttyWeb/index.js'; import { Logger } from '../../../src/util/logger.js'; @@ -88,7 +89,7 @@ describe('GhosttyWebBackend unit guards', () => { expect(recordedChunks).toEqual(chunks); }); - it('notes painted graphemes after each bridge batch of a split flush', async () => { + it('runs the after-batch hook after each bridge call of a split flush', async () => { const backend = createBackend(); const calls: string[] = []; ( @@ -113,29 +114,111 @@ describe('GhosttyWebBackend unit guards', () => { ) => Promise; } ).flushOutputBatch({}, chunks, () => { - calls.push('note'); + calls.push('hook'); return Promise.resolve(); }); expect(calls).toEqual([ 'write 1000', - 'note', + 'hook', 'write 1000', - 'note', + 'hook', 'write 501', - 'note', + 'hook', ]); }); - it('notes painted graphemes after each output flush of a timed replay', async () => { + // The page holds the chunks of the calls before the one that failed. + // HostRendererManager keeps the backend after a failed replay, so a retry + // would meet them. + describe.each([ + [ + 'a page call', + (calls: number) => (calls === 2 ? new Error('page call failed') : null), + undefined, + ], + [ + 'the hook between two calls', + () => null, + () => Promise.reject(new Error('page call failed')), + ], + ])('when %s of a flush fails', (_name, failure, afterEachBatch) => { + function failFlush(discard: () => unknown): { + rejection: Promise; + evaluate: ReturnType; + } { + const backend = createBackend(); + vi.stubGlobal('__agentTty', { discardHeldChunks: discard }); + const evaluate = vi.fn((pageFunction: () => unknown) => + Promise.resolve(pageFunction()), + ); + let calls = 0; + ( + backend as unknown as { + writeBatchBridge: () => Promise; + } + ).writeBatchBridge = () => { + calls += 1; + const error = failure(calls); + return error === null ? Promise.resolve() : Promise.reject(error); + }; + const rejection = ( + backend as unknown as { + flushOutputBatch: ( + page: object, + dataChunks: string[], + afterEachBatch?: () => Promise, + ) => Promise; + } + ).flushOutputBatch( + { evaluate }, + Array.from({ length: 2_501 }, () => 'x'), + afterEachBatch, + ); + return { rejection, evaluate }; + } + + afterEach(() => { + vi.unstubAllGlobals(); + }); + + it('drops the held chunks and rejects with the original error', async () => { + const discard = vi.fn(); + const { rejection } = failFlush(discard); + + await expect(rejection).rejects.toThrow('page call failed'); + expect(discard).toHaveBeenCalledTimes(1); + }); + + it('rejects with the original error when the page cannot drop the chunks either', async () => { + const { rejection, evaluate } = failFlush(() => { + throw new Error('page crashed'); + }); + + await expect(rejection).rejects.toThrow('page call failed'); + expect(evaluate).toHaveBeenCalledTimes(1); + }); + }); + + // A separate page call costs a round trip behind a frame, 5 to 60 ms + // depending on the terminal size, so the page notes the graphemes inside the + // call that ends the flush. + it('notes painted graphemes in the page call that ends each output flush of a timed replay', async () => { const backend = createBackend(); const calls: string[] = []; Object.assign(backend as object, { isBooted: true, page: { isClosed: () => false }, resizeBridge: () => Promise.resolve(), - writeBatchBridge: (_page: object, dataChunks: string[]) => { - calls.push(`write ${dataChunks.join(',')}`); + writeBatchBridge: ( + _page: object, + dataChunks: string[], + endsFlush: boolean, + paintedCap: number | null, + ) => { + calls.push( + `write ${dataChunks.join(',')} ${String(endsFlush)} ${String(paintedCap)}`, + ); return Promise.resolve(); }, notePaintedGraphemes: () => { @@ -184,7 +267,48 @@ describe('GhosttyWebBackend unit guards', () => { { mode: 'max-speed', minFrameHoldMs: 0, finalFrameHoldMs: 0 }, ); - expect(calls).toEqual(['write first', 'note', 'write second', 'note']); + expect(calls).toEqual([ + `write first true ${String(MAX_CACHED_GLYPH_PROBES)}`, + `write second true ${String(MAX_CACHED_GLYPH_PROBES)}`, + ]); + }); + + it('omits the record export glyph fields, and asks for no more notes, once the page reports a failed note', async () => { + const logger = new Logger('debug'); + const debugSpy = vi.spyOn(logger, 'debug').mockImplementation(() => {}); + const backend = new GhosttyWebBackend( + 'renderer-unit-session', + PROFILE, + undefined, + logger, + ); + const evaluate = vi.fn(() => Promise.resolve('grapheme read failed')); + const page = { isClosed: () => false, evaluate }; + Object.assign(backend as object, { isBooted: true, page }); + const flush = (cap: number | null): Promise => + ( + backend as unknown as { + writeBatchBridge: ( + page: object, + dataChunks: string[], + endsFlush: boolean, + paintedCap: number | null, + ) => Promise; + } + ).writeBatchBridge(page, ['x'], true, cap); + + await expect(flush(MAX_CACHED_GLYPH_PROBES)).resolves.toBeUndefined(); + + expect(debugSpy).toHaveBeenCalledWith( + 'Missing-glyph note failed; the record export result omits missingGlyphs', + 'grapheme read failed', + ); + await expect(backend.recordedMissingGlyphs()).resolves.toEqual({}); + expect( + ( + backend as unknown as { paintedNoteCap: () => number | null } + ).paintedNoteCap(), + ).toBeNull(); }); it('retries the painted-grapheme note after the backend reboots', async () => { @@ -426,6 +550,224 @@ describe('GhosttyWebBackend unit guards', () => { expect(evaluate).not.toHaveBeenCalled(); }); + // The page waits one animation frame (about 17 ms) after each bridge write. + // A bridge call that writes its chunks one by one makes a replay cost one + // frame per output event, so these tests run the page function of every + // call against a counting bridge. + async function withCountingBridge( + run: (context: { + page: { isClosed: () => boolean; evaluate: ReturnType }; + write: ReturnType; + writeBatchSizes: number[]; + frameWaits: boolean[]; + paintedCaps: (number | null)[]; + writtenChunks: string[]; + }) => Promise, + ): Promise { + const writeBatchSizes: number[] = []; + const frameWaits: boolean[] = []; + const paintedCaps: (number | null)[] = []; + const writtenChunks: string[] = []; + const write = vi.fn(() => Promise.resolve()); + vi.stubGlobal('__agentTty', { + write, + writeBatch: ( + chunks: string[], + waitForFrame: boolean, + paintedCap: number | null, + ) => { + writeBatchSizes.push(chunks.length); + frameWaits.push(waitForFrame); + paintedCaps.push(paintedCap); + writtenChunks.push(...chunks); + return Promise.resolve(null); + }, + }); + const page = { + isClosed: () => false, + evaluate: vi.fn((pageFunction: (arg: unknown) => unknown, arg: unknown) => + Promise.resolve(pageFunction(arg)), + ), + }; + + try { + return await run({ + page, + write, + writeBatchSizes, + frameWaits, + paintedCaps, + writtenChunks, + }); + } finally { + vi.unstubAllGlobals(); + } + } + + function outputReplayInput(eventCount: number): ReplayInput { + return { + sessionId: 'renderer-unit-session', + initialCols: 80, + initialRows: 24, + targetSeq: eventCount - 1, + events: Array.from({ length: eventCount }, (_, seq) => ({ + seq, + ts: '2026-03-19T12:00:00.000Z', + type: 'output' as const, + payload: { data: `chunk-${String(seq)}` }, + })), + }; + } + + it('writes a bridge batch into the page in one call that ends its flush', async () => { + const backend = createBackend(); + const chunks = Array.from({ length: 1000 }, (_, i) => `chunk-${String(i)}`); + + await withCountingBridge( + async ({ page, write, writeBatchSizes, frameWaits, writtenChunks }) => { + await ( + backend as unknown as { + writeBatchBridge: ( + page: object, + dataChunks: string[], + ) => Promise; + } + ).writeBatchBridge(page, chunks); + + expect(page.evaluate).toHaveBeenCalledTimes(1); + expect(writeBatchSizes).toEqual([1000]); + expect(frameWaits).toEqual([true]); + expect(writtenChunks).toEqual(chunks); + expect(write).not.toHaveBeenCalled(); + }, + ); + }); + + // Only a recorded replay probes glyphs, and it notes the painted graphemes + // in the call that ends the flush: no call of its own, and none in a call + // that only holds chunks. + it.each([ + [ + 'replayTo', + (backend: GhosttyWebBackend, input: ReplayInput) => + backend.replayTo(input), + [null, null, null], + ], + [ + 'replayWithTiming', + (backend: GhosttyWebBackend, input: ReplayInput) => + backend.replayWithTiming(input, { + mode: 'max-speed', + minFrameHoldMs: 0, + finalFrameHoldMs: 0, + }), + [null, null, MAX_CACHED_GLYPH_PROBES], + ], + ])( + '%s calls the page once per 1000 output events, and ends the flush with the last call', + async (_name, replay, expectedPaintedCaps) => { + const backend = createBackend(); + const input = outputReplayInput(2_501); + + await withCountingBridge( + async ({ + page, + write, + writeBatchSizes, + frameWaits, + paintedCaps, + writtenChunks, + }) => { + Object.assign(backend as object, { + isBooted: true, + page, + resizeBridge: () => Promise.resolve(), + checkPaintedGlyphs: () => Promise.resolve({}), + readHarnessSnapshot: () => + Promise.resolve(createHarnessSnapshotPayload({ cols: 80 })), + }); + + await replay(backend, input); + + expect(page.evaluate).toHaveBeenCalledTimes(3); + expect(writeBatchSizes).toEqual([1000, 1000, 501]); + expect(frameWaits).toEqual([false, false, true]); + expect(paintedCaps).toEqual(expectedPaintedCaps); + expect(writtenChunks).toEqual( + input.events.map((event) => + event.type === 'output' ? event.payload.data : '', + ), + ); + expect(write).not.toHaveBeenCalled(); + }, + ); + }, + ); + + // A bridge call holds at most 1000 chunks. The page writes a flush when the + // call that ends it arrives, so the flag must be true on exactly one call of + // a flush, the last: also when the chunk count is a multiple of 1000. + it.each([ + [1, [true]], + [999, [true]], + [1_000, [true]], + [1_001, [false, true]], + [1_999, [false, true]], + [2_000, [false, true]], + [2_001, [false, false, true]], + ])( + 'ends a flush of %i output chunks with its last bridge call only', + async (chunkCount, expectedEnds) => { + const backend = createBackend(); + + await withCountingBridge( + async ({ page, writeBatchSizes, frameWaits }) => { + Object.assign(backend as object, { + isBooted: true, + page, + resizeBridge: () => Promise.resolve(), + readHarnessSnapshot: () => + Promise.resolve(createHarnessSnapshotPayload({ cols: 80 })), + }); + + await backend.replayTo(outputReplayInput(chunkCount)); + + expect(frameWaits).toEqual(expectedEnds); + expect(writeBatchSizes.reduce((sum, size) => sum + size, 0)).toBe( + chunkCount, + ); + }, + ); + }, + ); + + it('ends the flush before a marker, so the next flush starts holding again', async () => { + const backend = createBackend(); + const input = outputReplayInput(3_001); + input.events[1_500] = { + seq: 1_500, + ts: '2026-03-19T12:00:00.000Z', + type: 'marker', + payload: { label: 'boundary' }, + }; + + await withCountingBridge(async ({ page, writeBatchSizes, frameWaits }) => { + Object.assign(backend as object, { + isBooted: true, + page, + resizeBridge: () => Promise.resolve(), + readHarnessSnapshot: () => + Promise.resolve(createHarnessSnapshotPayload({ cols: 80 })), + }); + + await backend.replayTo(input); + + // 1500 chunks, the marker, then 1500 chunks. + expect(writeBatchSizes).toEqual([1_000, 500, 1_000, 500]); + expect(frameWaits).toEqual([false, true, false, true]); + }); + }); + it('includes structured cell data only when snapshot includeCells is requested', async () => { const backend = createBackend(); const evaluate = vi.fn().mockResolvedValue( @@ -1115,17 +1457,38 @@ describe('GhosttyWebBackend replayWithTiming output pacing', () => { }; } + function inputEvent( + seq: number, + offsetMs: number, + ): ReplayInput['events'][number] { + return { + seq, + ts: new Date(BASE_TIMESTAMP_MS + offsetMs).toISOString(), + type: 'input_text', + payload: { data: 'x' }, + }; + } + async function replayAndRecordFlushes( events: ReplayInput['events'], timing: ReplayTimingOptions, flushCostMs = 0, onFlush: () => void = () => {}, + // Seq that an earlier replay applied: the backend starts after it. + appliedSeq = -1, ): Promise<{ atMs: number; chunks: string[] }[]> { vi.useFakeTimers(); const backend = createBackend(); const flushes: { atMs: number; chunks: string[] }[] = []; let replayStartedAtMs = 0; + if (appliedSeq >= 0) { + Object.assign(backend as object, { + lastAppliedSeq: appliedSeq, + initialReplayCols: 80, + initialReplayRows: 24, + }); + } Object.assign(backend as object, { isBooted: true, page: { isClosed: () => false }, @@ -1169,6 +1532,82 @@ describe('GhosttyWebBackend replayWithTiming output pacing', () => { })); } + function resizeEvent( + seq: number, + offsetMs: number, + ): ReplayInput['events'][number] { + return { + seq, + ts: new Date(BASE_TIMESTAMP_MS + offsetMs).toISOString(), + type: 'resize', + payload: { cols: 100, rows: 30 }, + }; + } + + // The steps of a replay with the time of each, counted from the resize that + // sets the initial size: `flush` is a write of pending output, `resize` and + // `note` follow a resize event, `snapshot` is the read of the final state. + async function replayAndRecordTimeline( + events: ReplayInput['events'], + timing: ReplayTimingOptions, + ): Promise<{ step: string; atMs: number }[]> { + vi.useFakeTimers(); + const backend = createBackend(); + const timeline: { step: string; atMs: number }[] = []; + let replayStartedAtMs: number | undefined; + const record = (step: string): void => { + timeline.push({ + step, + atMs: performance.now() - (replayStartedAtMs ?? performance.now()), + }); + }; + + Object.assign(backend as object, { + isBooted: true, + page: { isClosed: () => false }, + resizeBridge: (_page: object, cols: number) => { + if (replayStartedAtMs === undefined) { + replayStartedAtMs = performance.now(); + } else { + record(`resize ${String(cols)}`); + } + return Promise.resolve(); + }, + flushOutputBatch: (_page: object, dataChunks: string[]) => { + record(`flush ${dataChunks.join(',')}`); + return Promise.resolve(); + }, + notePaintedGraphemes: () => { + record('note'); + return Promise.resolve(); + }, + readHarnessSnapshot: () => { + record('snapshot'); + return Promise.resolve( + createHarnessSnapshotPayload({ + cols: 80, + rows: 24, + visibleLines: [], + }), + ); + }, + }); + + const replay = backend.replayWithTiming( + { + sessionId: 'renderer-unit-session', + initialCols: 80, + initialRows: 24, + targetSeq: Math.max(...events.map((event) => event.seq)), + events, + }, + timing, + ); + await vi.runAllTimersAsync(); + await replay; + return timeline; + } + it('shows each output at its recorded time when the outputs are far apart', async () => { const flushes = await replayAndRecordFlushes( [ @@ -1266,15 +1705,259 @@ describe('GhosttyWebBackend replayWithTiming output pacing', () => { ]); }); - it('keeps max-speed outputs in one flush so frame holds cannot outlast the export timeout', async () => { + it('ends a max-speed flush at the first event that is a frame hold after the first output of the batch', async () => { const flushes = await replayAndRecordFlushes( - [outputEvent(0, 0), outputEvent(1, 200), outputEvent(2, 400)], + [ + outputEvent(0, 0), + outputEvent(1, 5), + outputEvent(2, 10), + outputEvent(3, 16), + outputEvent(4, 20), + outputEvent(5, 40), + outputEvent(6, 41), + exitEvent(7, 500), + ], MAX_SPEED, ); + expect(flushes.map((flush) => flush.chunks)).toEqual([ + ['out0', 'out1', 'out2'], + ['out3', 'out4'], + ['out5', 'out6'], + ]); + }); + + it('keeps one max-speed flush per output when the outputs are far apart', async () => { + const flushes = await replayAndRecordFlushes( + [ + outputEvent(0, 0), + outputEvent(1, 200), + outputEvent(2, 400), + exitEvent(3, 600), + ], + MAX_SPEED, + ); + + expect(flushes.map((flush) => flush.chunks)).toEqual([ + ['out0'], + ['out1'], + ['out2'], + ]); + }); + + // The frame wait of a flush is its frame. A hold after every + // flush would make each 30 ms step cost 44 ms to export. + it('holds max-speed frames only after the last flush of the replay', async () => { + const flushes = await replayAndRecordFlushes( + [ + outputEvent(0, 0), + outputEvent(1, 20), + outputEvent(2, 40), + exitEvent(3, 50), + outputEvent(4, 80), + ], + MAX_SPEED, + ); + + // Every flush starts when the next event arrives, so no hold follows one. expect(flushes).toEqual([ - { atMs: FIRST_EVENT_AT_MS, chunks: ['out0', 'out1', 'out2'] }, + { atMs: FIRST_EVENT_AT_MS, chunks: ['out0'] }, + { atMs: FIRST_EVENT_AT_MS, chunks: ['out1'] }, + { atMs: FIRST_EVENT_AT_MS, chunks: ['out2'] }, + { atMs: FIRST_EVENT_AT_MS, chunks: ['out4'] }, + ]); + }); + + // The page paints a flush on its next animation frame. The hold gives that + // paint time to reach the video before the resize changes the canvas. + it('holds one frame hold between the last flush and a resize', async () => { + const timeline = await replayAndRecordTimeline( + [ + outputEvent(0, 0), + resizeEvent(1, 5), + outputEvent(2, 10), + exitEvent(3, 12), + ], + { mode: 'max-speed', minFrameHoldMs: 16, finalFrameHoldMs: 0 }, + ); + + expect(timeline.map((entry) => entry.step)).toEqual([ + 'flush out0', + 'resize 100', + 'note', + 'flush out2', + 'snapshot', + ]); + const atMs = (step: string): number | undefined => + timeline.find((entry) => entry.step === step)?.atMs; + expect((atMs('resize 100') ?? 0) - (atMs('flush out0') ?? 0)).toBe(16); + }); + + it.each([ + ['recorded', RECORDED], + ['max-speed', MAX_SPEED], + ])( + 'notes the painted graphemes right after a resize event, in %s mode', + async (_name, timing) => { + const timeline = await replayAndRecordTimeline( + [ + outputEvent(0, 0), + resizeEvent(1, 200), + outputEvent(2, 400), + exitEvent(3, 600), + ], + timing, + ); + + const steps = timeline.map((entry) => entry.step); + const resizeAt = steps.indexOf('resize 100'); + expect(resizeAt).toBeGreaterThan(0); + expect(steps[resizeAt + 1]).toBe('note'); + expect(timeline[resizeAt + 1]?.atMs).toBe(timeline[resizeAt]?.atMs); + }, + ); + + it('holds one frame hold after a resize, and one after the last flush of the replay', async () => { + const timeline = await replayAndRecordTimeline( + [ + outputEvent(0, 0), + resizeEvent(1, 5), + outputEvent(2, 10), + exitEvent(3, 12), + ], + { mode: 'max-speed', minFrameHoldMs: 16, finalFrameHoldMs: 0 }, + ); + + const atMs = (step: string): number => + timeline.find((entry) => entry.step === step)?.atMs ?? Number.NaN; + expect(atMs('flush out2') - atMs('note')).toBe(16); + expect(atMs('snapshot') - atMs('flush out2')).toBe(16); + }); + + // A flush at every input, marker or exit event would cost one frame for each + // of them, and a recording of typing has an input for every output. + it('does not end a max-speed flush at an event that changes no pixel', async () => { + const flushes = await replayAndRecordFlushes( + [ + outputEvent(0, 0), + inputEvent(1, 5), + outputEvent(2, 10), + exitEvent(3, 500), + ], + MAX_SPEED, + ); + + expect(flushes.map((flush) => flush.chunks)).toEqual([['out0', 'out2']]); + }); + + it('still ends a recorded flush at an event that changes no pixel', async () => { + const flushes = await replayAndRecordFlushes( + [ + outputEvent(0, 0), + inputEvent(1, 5), + outputEvent(2, 10), + exitEvent(3, 500), + ], + RECORDED, + ); + + expect(flushes.map((flush) => flush.chunks)).toEqual([['out0'], ['out2']]); + }); + + // 9,000 outputs over 180 s or 360 s. Without a budget, every output is a + // flush of its own and the replay makes 9,000 flushes of a frame each. With + // a budget of 2,400 flushes, a flush ends at the first event that is 75 ms or + // 150 ms (span / 2,400) after the first output of its batch. That is the + // fourth output in both cases: 2,250 flushes. A budget of 2,000 flushes gives + // 1,800, and one of 3,000 flushes gives 3,000. + it.each([ + { label: 'outputs 20 ms apart', outputGapMs: 20, withInputs: false }, + { + label: 'outputs 40 ms apart with an input between', + outputGapMs: 40, + withInputs: true, + }, + ])( + 'ends a max-speed flush every 1/2,400 of the recorded span: 9,000 $label make 2,250 flushes', + async ({ outputGapMs, withInputs }) => { + const events: ReplayInput['events'] = []; + for (let index = 0; index < 9_000; index += 1) { + events.push(outputEvent(events.length, outputGapMs * index)); + if (withInputs) { + events.push(inputEvent(events.length, outputGapMs * index + 20)); + } + } + events.push(exitEvent(events.length, 180_000 * (withInputs ? 2 : 1))); + const flushes = await replayAndRecordFlushes(events, MAX_SPEED); + + expect(flushes.length).toBe(2_250); + // No output is lost or moved. + expect(flushes.flatMap((flush) => flush.chunks)).toEqual( + events + .filter((event) => event.type === 'output') + .map((event) => `out${String(event.seq)}`), + ); + }, + ); + + it('measures the frame budget over the events that the replay applies', async () => { + // 20 ms apart: the whole log spans 200 s, but the last 10 events span 180 ms. + const events = Array.from({ length: 10_000 }, (_, index) => + outputEvent(index, index * 20), + ); + const flushes = await replayAndRecordFlushes( + events, + MAX_SPEED, + 0, + () => {}, + 9_989, + ); + + // 20 ms apart is above the frame hold of 16 ms: a flush each. + expect(flushes.map((flush) => flush.chunks)).toEqual( + events.slice(9_990).map((event) => [`out${String(event.seq)}`]), + ); + }); + + it('does not merge max-speed flushes when a flush costs more than a frame hold', async () => { + const events = Array.from({ length: 101 }, (_, index) => + outputEvent(index, index * 10), + ); + events.push(exitEvent(101, 1_000)); + const flushes = await replayAndRecordFlushes(events, MAX_SPEED, 30); + + // Recorded timing lets batches grow while the replay is behind its + // schedule. Max-speed has no schedule, so a slow flush must not merge two + // flushes: every flush holds the outputs of one frame hold (two events). + expect(flushes.length).toBe(51); + expect(flushes.every((flush) => flush.chunks.length <= 2)).toBe(true); + expect(flushes.flatMap((flush) => flush.chunks)).toEqual( + events.slice(0, 101).map((event) => `out${String(event.seq)}`), + ); + }); + + it('keeps accelerated frames at least one frame hold of recorded time apart', async () => { + const accelerated: ReplayTimingOptions = { + mode: 'accelerated', + maxGapMs: 400, + minFrameHoldMs: 100, + finalFrameHoldMs: 1_000, + }; + const events = Array.from({ length: 41 }, (_, index) => + outputEvent(index, index * 30), + ); + events.push(exitEvent(41, 1_300)); + const flushes = await replayAndRecordFlushes(events, accelerated); + + // 30 ms steps, 100 ms holds: a flush takes the outputs of four steps. + expect(flushes.map((flush) => flush.chunks.length)).toEqual([ + 4, 4, 4, 4, 4, 4, 4, 4, 4, 4, 1, ]); + for (let index = 1; index < flushes.length; index += 1) { + const gapMs = + (flushes[index]?.atMs ?? 0) - (flushes[index - 1]?.atMs ?? 0); + expect(gapMs).toBeGreaterThanOrEqual(100); + } }); it('refreshes continuous output at least once per frame hold', async () => {