diff --git a/crates/protocol/src/event.rs b/crates/protocol/src/event.rs index c22aef45..5e797129 100644 --- a/crates/protocol/src/event.rs +++ b/crates/protocol/src/event.rs @@ -663,6 +663,14 @@ pub enum RuntimeEventKind { // from the shipped schema entirely (see NOT_WIRE_MESSAGE_ROOTS in // crates/xtask/src/main.rs), so it has no name a schema consumer could // look up; that's why the shipped description below doesn't say it. +/// `OutOfBandInput::input_count`'s default for a row journaled before +/// coalescing existed: such a row is exactly one input, never zero -- an +/// `OutOfBandInput` event means "a human typed", and a row asserting zero +/// of them would contradict its own existence. +fn one_input() -> u64 { + 1 +} + /// A sanitized, durable runtime event. Fields are plain, already-sanitized /// values, so raw thinking/secret content can never reach the durable log /// through this type. @@ -943,10 +951,31 @@ pub enum RuntimeEvent { }, /// A human typed directly into a native pane, bypassing the /// adapter. Sets the run's `RunFlags.needsReconciliation` flag. + /// + /// Coalesced: one row covers every out-of-band input observed during + /// one idle window, not one row per keystroke read. Journaled at the + /// END of the window it describes, so the window's start is this + /// event's own envelope timestamp minus `spanMs` -- no separate start + /// timestamp is carried, to avoid a second place for the two to + /// disagree. OutOfBandInput { run_id: RunId, backend: DisplayBackend, pane_ref: String, + /// How many out-of-band inputs this row coalesces. Absent on + /// rows written before coalescing existed; such a row is exactly + /// one input, so absence reads as 1, never 0 -- an + /// `outOfBandInput` event means "a human typed", and zero of + /// them is not a state that can be journaled. + #[serde(default = "one_input")] + #[ts(type = "number")] + input_count: u64, + /// Milliseconds between the first and last input this row + /// coalesces. Absent on rows written before coalescing existed; + /// such a row is a single input, which spans zero milliseconds. + #[serde(default)] + #[ts(type = "number")] + span_ms: u64, }, // The resolved backend's pane creation failed, so the // run fell back to a hidden pane instead of the one it actually diff --git a/crates/runtime/src/adapter/event_sink.rs b/crates/runtime/src/adapter/event_sink.rs index 1d7e385a..312aae4c 100644 --- a/crates/runtime/src/adapter/event_sink.rs +++ b/crates/runtime/src/adapter/event_sink.rs @@ -134,12 +134,17 @@ pub enum AdapterEventPayload { /// A human typed directly into a TUI adapter's attached pane, /// bypassing the adapter's own input path. Carries no free text (the /// keystrokes themselves are never journaled) -- only that it - /// happened, on which pane. Maps to [`RuntimeEvent::OutOfBandInput`] - /// and additionally sets the run's `needsReconciliation` flag (see - /// [`DomainAdapterEventSink::emit`]). + /// happened, on which pane, how many times, and over what span. + /// Maps to [`RuntimeEvent::OutOfBandInput`] and additionally sets the + /// run's `needsReconciliation` flag (see + /// [`DomainAdapterEventSink::emit`]). Coalesced by the caller (see + /// `adapter::tui::oob_coalescer`) -- one payload per idle window, not + /// one per read. OutOfBandInput { backend: crew_protocol::DisplayBackend, pane_ref: String, + input_count: u64, + span_ms: u64, }, } @@ -406,13 +411,18 @@ impl DomainAdapterEventSink { worker_id, question: self.sanitize(text), }, - AdapterEventPayload::OutOfBandInput { backend, pane_ref } => { - RuntimeEvent::OutOfBandInput { - run_id, - backend, - pane_ref, - } - } + AdapterEventPayload::OutOfBandInput { + backend, + pane_ref, + input_count, + span_ms, + } => RuntimeEvent::OutOfBandInput { + run_id, + backend, + pane_ref, + input_count, + span_ms, + }, } } } @@ -934,6 +944,8 @@ mod out_of_band_input_tests { payload: AdapterEventPayload::OutOfBandInput { backend: DisplayBackend::Tmux, pane_ref: "%3".to_string(), + input_count: 7, + span_ms: 850, }, cursor: None, }) @@ -946,10 +958,20 @@ mod out_of_band_input_tests { run_id: got_run_id, backend, pane_ref, + input_count, + span_ms, } => { assert_eq!(*got_run_id, run_id); assert_eq!(*backend, DisplayBackend::Tmux); assert_eq!(pane_ref, "%3"); + assert_eq!( + *input_count, 7, + "the coalesced count must survive the round trip" + ); + assert_eq!( + *span_ms, 850, + "the coalesced span must survive the round trip" + ); } other => panic!("expected OutOfBandInput, got {other:?}"), } @@ -996,6 +1018,8 @@ mod out_of_band_input_tests { payload: AdapterEventPayload::OutOfBandInput { backend: DisplayBackend::Hidden, pane_ref: String::new(), + input_count: 1, + span_ms: 0, }, cursor: None, }) diff --git a/crates/runtime/src/adapter/tui/adapter.rs b/crates/runtime/src/adapter/tui/adapter.rs index 94d72fff..ec132422 100644 --- a/crates/runtime/src/adapter/tui/adapter.rs +++ b/crates/runtime/src/adapter/tui/adapter.rs @@ -1024,28 +1024,38 @@ impl TuiAdapter { Arc::new(StdMutex::new((DisplayBackend::Hidden, String::new()))); let attach_sink = Arc::clone(&sink); let attach_identity = Arc::clone(&pane_identity); + // Coalesced (see `oob_coalescer`'s own doc comment): a burst of + // out-of-band input reads journals one row, not one per read. + let coalescer = super::oob_coalescer::OobCoalescer::spawn(move |input_count, span_ms| { + let sink = Arc::clone(&attach_sink); + let (backend, pane_ref) = { + let guard = attach_identity + .lock() + .expect("pane identity mutex never poisoned"); + (guard.0, guard.1.clone()) + }; + tokio::spawn(async move { + emit( + &sink, + run_id, + task_id, + worker_id, + AdapterEventPayload::OutOfBandInput { + backend, + pane_ref, + input_count, + span_ms, + }, + None, + ) + .await; + }); + }); let attach = match AttachServer::start( self.socket_path(run_id), Arc::clone(&pty) as Arc, Box::new(move |_bytes: Vec| { - let sink = Arc::clone(&attach_sink); - let (backend, pane_ref) = { - let guard = attach_identity - .lock() - .expect("pane identity mutex never poisoned"); - (guard.0, guard.1.clone()) - }; - tokio::spawn(async move { - emit( - &sink, - run_id, - task_id, - worker_id, - AdapterEventPayload::OutOfBandInput { backend, pane_ref }, - None, - ) - .await; - }); + coalescer.notify(); }), ) { Ok(server) => Arc::new(server), @@ -1289,10 +1299,10 @@ impl TuiAdapter { // itself indistinguishable from a real vendor session id once // journaled) -- `runs.vendor_session_id` simply stays unset until // a real `SessionMeta` entry establishes it. - if let Some(initial_session_id) = self + let initial_session_id = self .vendor - .session_id_from_transcript_path(&transcript_path) - { + .session_id_from_transcript_path(&transcript_path); + if let Some(initial_session_id) = initial_session_id.clone() { emit( &sink, run_id, @@ -1320,8 +1330,38 @@ impl TuiAdapter { let pump_sink = Arc::clone(&sink); tokio::spawn(async move { + // A transcript format that stamps every entry with its + // session id (Claude's does) would otherwise re-derive and + // re-journal an identical `VendorSessionEstablished` on + // every single entry -- 41 identical rows for one id, + // measured on a real transcript. Only a CHANGE reaches + // `emit_tui_event`; seeded from the initial guess above so a + // first real entry that merely confirms it is a no-op too, + // not a second, redundant journal write for the same fact. + // + // Skipping is gated on `cursor.is_none()` too, never on the + // session id alone: `cursor_placements` already gives a + // `SessionMeta` paired with another event on its line (the + // common shape -- e.g. `SessionMeta` + `AssistantText`) no + // cursor at all, since the OTHER event carries it -- that + // case is free to skip. The rare "hidden SessionMeta-only + // line" this module's tests call out DOES carry a cursor + // (nothing else on the line to carry it instead), so it is + // still emitted even when redundant: dropping that call + // would drop the only commit that advances + // `runs.transcript_cursor` past it, which a resume must + // never do (see `cursor_placements`'s own doc comment). + let mut last_vendor_session_id = initial_session_id; while let Some((tagged, _new_cursor)) = batch_rx.recv().await { for (event, cursor) in cursor_placements(tagged) { + if let TuiEvent::SessionMeta { vendor_session_id } = &event { + let unchanged = + last_vendor_session_id.as_deref() == Some(vendor_session_id.as_str()); + if unchanged && cursor.is_none() { + continue; + } + last_vendor_session_id = Some(vendor_session_id.clone()); + } emit_tui_event(&pump_sink, run_id, task_id, worker_id, event, cursor).await; } } diff --git a/crates/runtime/src/adapter/tui/mod.rs b/crates/runtime/src/adapter/tui/mod.rs index 5a1d5e30..59472223 100644 --- a/crates/runtime/src/adapter/tui/mod.rs +++ b/crates/runtime/src/adapter/tui/mod.rs @@ -31,6 +31,7 @@ mod classify; mod discovery; mod grid; mod input; +pub(crate) mod oob_coalescer; mod screen; mod tailer; mod verify; diff --git a/crates/runtime/src/adapter/tui/oob_coalescer.rs b/crates/runtime/src/adapter/tui/oob_coalescer.rs new file mode 100644 index 00000000..fc8032b8 --- /dev/null +++ b/crates/runtime/src/adapter/tui/oob_coalescer.rs @@ -0,0 +1,162 @@ +//! Coalesces rapid out-of-band-input notifications into one journaled +//! row per idle window, rather than one row per read. +//! +//! The other half of the echo-storm fix: `display::terminal_reply`'s filter already +//! keeps a vendor's own terminal-reply storm from reaching +//! `on_user_input` at all, but a human genuinely typing directly into an +//! attached pane -- bypassing the adapter, which is what `OutOfBandInput` +//! exists to notice -- can still fire it once per keystroke read. Each +//! firing used to journal its own row and set `needsReconciliation` +//! immediately; this batches a burst of firings into one row (a count +//! and a span), journaled once the burst goes quiet. + +use std::time::{Duration, Instant}; + +use tokio::sync::mpsc; + +/// How long a run of out-of-band input must stay quiet before the batch +/// it belongs to is flushed. Short enough that a single, isolated +/// keystroke still journals promptly; long enough to coalesce a redraw +/// storm's rapid successive firings (measured at 50-200ms apart) into +/// one row per second or so of continuous activity, rather than one row +/// per firing. +/// +/// Shared with `display::terminal_reply::ReplyFilter`'s own idle flush: +/// a byte that filter holds back (possibly the first byte of a +/// sequence a later read completes) is released as content on the same +/// cadence, rather than inventing a second timer value to keep in sync. +pub(crate) const IDLE_WINDOW: Duration = Duration::from_secs(1); + +/// Notifies [`OobCoalescer::spawn`]'s background task of one out-of-band +/// input occurrence. Cloneable so every viewer connection's own callback +/// can hold one without sharing a lock. +#[derive(Clone)] +pub struct OobCoalescer { + tx: mpsc::UnboundedSender<()>, +} + +impl OobCoalescer { + /// Spawns the coalescing background task and returns a handle to + /// notify it. `flush(input_count, span_ms)` is called once per + /// batch, after `IDLE_WINDOW` has passed with no further + /// notifications -- never more often, however fast `notify` is + /// called. Dropping every clone of the returned handle ends the + /// task (its `notify` channel closes, which is also observed as a + /// final flush of any in-progress batch, matching a caller that + /// stops without an explicit shutdown call). + #[must_use] + pub fn spawn(mut flush: impl FnMut(u64, u64) + Send + 'static) -> Self { + let (tx, mut rx) = mpsc::unbounded_channel::<()>(); + tokio::spawn(async move { + loop { + // Wait for the first notification of a new batch -- + // idling here costs nothing and keeps a run with no + // out-of-band input at all from ever flushing anything. + if rx.recv().await.is_none() { + return; + } + let mut count: u64 = 1; + let first_at = Instant::now(); + loop { + match tokio::time::timeout(IDLE_WINDOW, rx.recv()).await { + Ok(Some(())) => count += 1, + Ok(None) => { + flush(count, ms_since(first_at)); + return; + } + Err(_elapsed) => break, + } + } + flush(count, ms_since(first_at)); + } + }); + Self { tx } + } + + /// Records one out-of-band input occurrence, extending the current + /// batch (or starting a new one if the last batch already flushed). + /// Never blocks and never fails observably: the channel is + /// unbounded, and a send after the task has already exited (a race + /// with shutdown) is silently dropped -- losing one notification + /// during shutdown is a missed row, not a wrong one. + pub fn notify(&self) { + let _ = self.tx.send(()); + } +} + +fn ms_since(instant: Instant) -> u64 { + u64::try_from(instant.elapsed().as_millis()).unwrap_or(u64::MAX) +} + +#[cfg(test)] +mod tests { + use std::sync::{Arc, Mutex}; + + use super::OobCoalescer; + + #[tokio::test] + async fn a_single_notification_flushes_as_one_input_with_a_zero_span() { + let flushes: Arc>> = Arc::new(Mutex::new(Vec::new())); + let recorded = Arc::clone(&flushes); + let coalescer = OobCoalescer::spawn(move |count, span_ms| { + recorded.lock().unwrap().push((count, span_ms)); + }); + + coalescer.notify(); + tokio::time::sleep(super::IDLE_WINDOW * 2).await; + + let got = flushes.lock().unwrap().clone(); + assert_eq!(got.len(), 1, "exactly one batch must flush: {got:?}"); + assert_eq!(got[0].0, 1, "a single notification is one input"); + } + + #[tokio::test] + async fn a_burst_within_the_idle_window_coalesces_into_one_row() { + let flushes: Arc>> = Arc::new(Mutex::new(Vec::new())); + let recorded = Arc::clone(&flushes); + let coalescer = OobCoalescer::spawn(move |count, span_ms| { + recorded.lock().unwrap().push((count, span_ms)); + }); + + for _ in 0..50 { + coalescer.notify(); + tokio::time::sleep(std::time::Duration::from_millis(5)).await; + } + tokio::time::sleep(super::IDLE_WINDOW * 2).await; + + let got = flushes.lock().unwrap().clone(); + assert_eq!( + got.len(), + 1, + "50 rapid notifications inside one idle window must coalesce into one row, not 50: {got:?}" + ); + assert_eq!( + got[0].0, 50, + "the one row must count every notification: {got:?}" + ); + } + + #[tokio::test] + async fn two_bursts_separated_by_a_quiet_gap_flush_as_two_rows() { + let flushes: Arc>> = Arc::new(Mutex::new(Vec::new())); + let recorded = Arc::clone(&flushes); + let coalescer = OobCoalescer::spawn(move |count, span_ms| { + recorded.lock().unwrap().push((count, span_ms)); + }); + + coalescer.notify(); + coalescer.notify(); + tokio::time::sleep(super::IDLE_WINDOW * 2).await; + coalescer.notify(); + tokio::time::sleep(super::IDLE_WINDOW * 2).await; + + let got = flushes.lock().unwrap().clone(); + assert_eq!( + got.len(), + 2, + "a quiet gap must start a new batch, not extend the old one: {got:?}" + ); + assert_eq!(got[0].0, 2); + assert_eq!(got[1].0, 1); + } +} diff --git a/crates/runtime/src/display/attach.rs b/crates/runtime/src/display/attach.rs index dad47f2c..0a97c205 100644 --- a/crates/runtime/src/display/attach.rs +++ b/crates/runtime/src/display/attach.rs @@ -417,6 +417,14 @@ async fn serve_viewer( } let mut buf = [0u8; READ_CHUNK_BYTES]; + // One filter per connection, spanning its whole read loop: a real + // terminal's reply to the vendor's own redraw-driven escape queries + // (CPR, DA, focus/paste-mode reports) shares this exact socket with + // genuine keystrokes -- see `terminal_reply`'s doc comment for the + // incident this exists for -- and a single socket read can split one + // reply across two calls, which only a filter carried across reads + // can see through (see `ReplyFilter`'s own doc comment). + let mut reply_filter = super::terminal_reply::ReplyFilter::new(); loop { tokio::select! { read = read_half.read(&mut buf) => { @@ -424,7 +432,18 @@ async fn serve_viewer( Ok(0) | Err(_) => return, Ok(n) => { let bytes = buf[..n].to_vec(); - on_user_input(bytes.clone()); + // Only the residue after stripping recognized + // replies is out-of-band INPUT; a read that is + // nothing but replies never reaches + // `on_user_input` at all, so it neither journals + // an event nor sets `needsReconciliation`. The + // vendor's own PTY still gets every byte, + // unfiltered, below -- stripping is for the + // journaling decision only. + let residue = reply_filter.filter(&bytes); + if !residue.is_empty() { + on_user_input(residue); + } // A failed keystroke delivery is degraded control, // never silence: the viewer typed and nothing // reached the vendor process (a deferred minor). @@ -446,6 +465,23 @@ async fn serve_viewer( Err(broadcast::error::RecvError::Closed) => return, } } + // `ReplyFilter` holds a trailing `ESC` back by volume, not + // time (more bytes arriving is what proves it wasn't a + // reply) -- a lone Escape keypress with nothing typed after + // it would otherwise be held forever, and Escape alone is a + // real, consequential out-of-band action (it interrupts a + // claude TUI's current turn). Disabled whenever nothing is + // held (`if reply_filter.has_pending()`), so an idle + // connection with no pending bytes never wakes this loop for + // nothing; re-armed fresh every iteration, so it always + // measures quiet time since the most recent read, matching + // `oob_coalescer`'s own idle-window cadence exactly (see + // `ReplyFilter`'s doc comment for why the two share one + // constant rather than each inventing their own). + () = tokio::time::sleep(crate::adapter::tui::oob_coalescer::IDLE_WINDOW), if reply_filter.has_pending() => { + let held = reply_filter.take_pending(); + on_user_input(held); + } } } } diff --git a/crates/runtime/src/display/mod.rs b/crates/runtime/src/display/mod.rs index 383f3e34..50b4615b 100644 --- a/crates/runtime/src/display/mod.rs +++ b/crates/runtime/src/display/mod.rs @@ -25,6 +25,7 @@ mod herdr; mod hidden; mod os_window; pub mod pane_socket; +mod terminal_reply; mod tmux; pub use attach::{AttachError, AttachServer, AttachTarget, PumpOutcome}; diff --git a/crates/runtime/src/display/terminal_reply.rs b/crates/runtime/src/display/terminal_reply.rs new file mode 100644 index 00000000..99f666b6 --- /dev/null +++ b/crates/runtime/src/display/terminal_reply.rs @@ -0,0 +1,354 @@ +//! Recognizes terminal-protocol reply/report sequences a real terminal +//! emulator generates on a viewer's behalf -- never something a human +//! typed -- so [`crate::display::attach`]'s `serve_viewer` can keep +//! forwarding them to the vendor's PTY (it is the only path that ever +//! answers the vendor's own escape queries) without treating them as +//! out-of-band keyboard input. +//! +//! The echo storm this exists for: a vendor TUI's redraw-driven cursor +//! position (CPR) and device attributes (DA) queries, relayed through +//! `crewd attach`'s mirrored output to whatever real terminal is watching +//! -- a human's, or, confirmed in production, tmux hosting the attach +//! pane in its own window/pane -- come back as replies on the SAME +//! socket ordinary keystrokes arrive on. Left unfiltered, every reply +//! journaled an `OutOfBandInput` event and set the run's +//! `needsReconciliation` flag: 99 in 20 seconds of pure idle, measured +//! against a live tmux pane answering a synthetic query storm. +//! +//! The patterns below match only sequences with a fixed shape a real +//! terminal emits automatically, never something a keyboard driver +//! produces: an arrow key (`ESC[A`) or a function/navigation key +//! (`ESC[3~`) share the `CSI ... final-byte` grammar but neither their +//! parameter shape nor final byte collides with any pattern here. + +use std::sync::LazyLock; + +use regex::bytes::Regex; + +const ESC: u8 = 0x1b; + +/// Every terminal-reply/report shape this module recognizes, as one +/// alternation so a single scan finds them all: +/// +/// * Cursor Position Report reply -- `CSI Pn ; Pn R` (a real terminal's +/// answer to the vendor's `ESC[6n` query). +/// * Primary Device Attributes reply -- `CSI ? Pn (; Pn)* c`. +/// * Secondary Device Attributes reply -- `CSI > Pn ; Pn ; Pn c`. +/// * Device Status Report "terminal OK" reply -- `CSI 0 n`. +/// * Focus in/out reports -- `CSI I` / `CSI O` (unsolicited, sent when +/// the terminal's own focus changes, never a keystroke). +/// * Bracketed-paste start/end markers -- `CSI 200 ~` / `CSI 201 ~`. +/// These wrap a paste's real content rather than replacing it: only +/// the marker bytes match here, so pasted text between them is left +/// alone and still counts as genuine input. +static TERMINAL_REPLY_PATTERN: LazyLock = LazyLock::new(|| { + Regex::new( + r"(?x-u) + \x1b\[ \d+ ; \d+ R # CPR reply + | \x1b\[ \? [\d;]* c # primary DA reply + | \x1b\[ > [\d;]* c # secondary DA reply + | \x1b\[ 0 n # DSR terminal-OK reply + | \x1b\[ [IO] # focus in / focus out report + | \x1b\[ 20[01] ~ # bracketed-paste start/end marker + ", + ) + .expect("terminal reply pattern must compile") +}); + +/// Removes every recognized terminal-reply/report sequence from `bytes`, +/// returning only the residue a human could plausibly have typed. A +/// mixed read (real keystrokes interleaved with replies, plausible once +/// a terminal is answering queries mid-session, since both share one +/// duplex stream) keeps its real bytes, untouched and in order, with +/// only the recognized sequences removed. +/// +/// Never call this to decide what reaches the vendor process -- the +/// original, unfiltered bytes are still forwarded there unconditionally +/// (a real terminal's reply is the only answer the vendor's own query +/// ever gets); this is for the journaling/reconciliation decision only. +/// +/// Operates on one already-complete buffer. A socket read can split a +/// reply sequence across two reads (measured live: a lone trailing `c` +/// or a truncated `ESC[?1;2;4` with the closing `c` in the next read), +/// which this function alone cannot see across -- use +/// [`ReplyFilter`] to filter a stream of reads instead. +pub fn strip_terminal_replies(bytes: &[u8]) -> Vec { + TERMINAL_REPLY_PATTERN + .replace_all(bytes, &b""[..]) + .into_owned() +} + +/// The longest sequence this module recognizes, generously bounded (the +/// longest in practice, a multi-parameter DA reply, is well under this). +/// Bounds how far back [`ReplyFilter`] looks for a trailing, possibly +/// incomplete sequence to hold back across reads. +const MAX_SEQUENCE_LEN: usize = 32; + +/// Filters a STREAM of reads (unlike the bare [`strip_terminal_replies`], +/// which only sees one buffer at a time and so cannot detect a reply +/// sequence a socket read split in two). Carries at most +/// [`MAX_SEQUENCE_LEN`] unresolved trailing bytes forward from one call +/// to the next: if a read ends with an `ESC` that has no recognized +/// sequence completed after it yet, those bytes are held rather than +/// released as residue, and reconsidered once the next read's bytes are +/// appended. A held-back byte still reaches the vendor's PTY on the +/// caller's own unfiltered path -- this only delays the +/// journaling/reconciliation decision for it, never delivery. +/// +/// Holding back is driven by volume (more bytes arriving), not time -- +/// on its own, a lone `ESC` with nothing after it (a human pressing +/// Escape once, alone, and then doing nothing else -- in a claude TUI, +/// Escape interrupts the turn, about as consequential an out-of-band +/// action as exists) would be held forever, since nothing ever arrives +/// to age it out. The caller MUST also poll [`ReplyFilter::has_pending`] +/// on an idle tick (`serve_viewer` uses the same window +/// `adapter::tui::oob_coalescer::IDLE_WINDOW` coalescing already ticks +/// on) and release whatever [`ReplyFilter::take_pending`] returns as +/// content once that tick fires with no intervening read -- a real +/// terminal answers within milliseconds, so anything still held after a +/// full idle window was never going to complete. +/// +/// One instance per viewer connection: `serve_viewer` owns one, for the +/// lifetime of that connection's read loop -- never shared across +/// connections, or one viewer's partial sequence could swallow another +/// viewer's keystroke. +#[derive(Default)] +pub struct ReplyFilter { + pending: Vec, +} + +impl ReplyFilter { + pub fn new() -> Self { + Self::default() + } + + /// Appends `chunk` to whatever was held back from the previous call, + /// strips every recognized sequence found in the now-safe prefix, + /// and returns the residue -- holding back a new trailing prefix in + /// turn if this chunk itself ends mid-sequence. + pub fn filter(&mut self, chunk: &[u8]) -> Vec { + self.pending.extend_from_slice(chunk); + let split_at = Self::safe_prefix_len(&self.pending); + let residue = strip_terminal_replies(&self.pending[..split_at]); + self.pending.drain(..split_at); + residue + } + + /// Whether this filter is currently holding back any bytes. The + /// caller checks this on its idle tick to decide whether + /// [`Self::take_pending`] has anything worth releasing. + pub fn has_pending(&self) -> bool { + !self.pending.is_empty() + } + + /// Drains and returns whatever this filter is currently holding + /// back, unconditionally treating it as content -- called only after + /// an idle window has passed with no further read, per this + /// struct's own doc comment on why that must happen at all. + pub fn take_pending(&mut self) -> Vec { + std::mem::take(&mut self.pending) + } + + /// The length of `buf`'s prefix that is safe to filter and release + /// now: everything up to (but not including) a trailing `ESC` -- + /// within the last `MAX_SEQUENCE_LEN` bytes of whatever remains + /// after every already-complete recognized sequence -- that has no + /// recognized sequence completed after it within `buf` itself. That + /// `ESC` might be the first byte of a sequence the next read + /// completes, so it and everything after it stay held back. + fn safe_prefix_len(buf: &[u8]) -> usize { + let after_last_match = TERMINAL_REPLY_PATTERN + .find_iter(buf) + .last() + .map_or(0, |m| m.end()); + let trailing = &buf[after_last_match..]; + let scan_from = trailing.len().saturating_sub(MAX_SEQUENCE_LEN); + for i in (scan_from..trailing.len()).rev() { + if trailing[i] == ESC { + return after_last_match + i; + } + } + buf.len() + } +} + +#[cfg(test)] +mod tests { + use super::{ReplyFilter, strip_terminal_replies}; + + /// The exact byte pairs captured live from a real tmux pane hosting + /// `crewd attach`, answering a fake vendor's `ESC[6n ESC[c` query + /// every 200ms with nobody typing (the echo-storm investigation's own + /// reproduction). This is the measured positive control: a filter + /// that fails to recognize this exact shape does not fix the bug + /// that was actually observed. + const CAPTURED_CPR_DA_REPLY: &[u8] = b"\x1b[17;67R\x1b[?1;2;4c"; + + #[test] + fn the_captured_cpr_da_reply_pair_strips_to_nothing() { + assert_eq!(strip_terminal_replies(CAPTURED_CPR_DA_REPLY), b""); + } + + /// The captured burst: 146 coalesced CPR+DA reply pairs arriving in + /// one 2493-byte socket read (measured live -- tmux/the kernel batch + /// replies under load rather than delivering one read per query). + /// The filter must treat a whole batch as zero keystrokes, not + /// (however implausibly) as one. + #[test] + fn a_coalesced_burst_of_146_replies_in_one_read_strips_to_nothing() { + let burst: Vec = CAPTURED_CPR_DA_REPLY.repeat(146); + assert_eq!(strip_terminal_replies(&burst), b""); + } + + #[test] + fn a_genuine_keystroke_survives_untouched() { + assert_eq!(strip_terminal_replies(b"hello"), b"hello"); + } + + #[test] + fn a_reply_interleaved_with_a_real_keystroke_leaves_only_the_keystroke() { + let mixed = [CAPTURED_CPR_DA_REPLY, b"q", CAPTURED_CPR_DA_REPLY].concat(); + assert_eq!(strip_terminal_replies(&mixed), b"q"); + } + + #[test] + fn an_arrow_key_is_never_mistaken_for_a_reply() { + // `ESC[A` (cursor up) shares the CSI introducer but neither the + // parameter shape nor the final byte of any recognized pattern. + assert_eq!(strip_terminal_replies(b"\x1b[A"), b"\x1b[A"); + } + + #[test] + fn a_navigation_key_ending_in_tilde_is_never_mistaken_for_a_paste_marker() { + // `ESC[3~` (Delete) -- shares the `~` terminator bracketed paste + // markers use, but not the `200`/`201` parameter. + assert_eq!(strip_terminal_replies(b"\x1b[3~"), b"\x1b[3~"); + } + + #[test] + fn bracketed_paste_markers_strip_but_the_pasted_text_between_them_survives() { + let pasted = b"\x1b[200~pasted text\x1b[201~"; + assert_eq!(strip_terminal_replies(pasted), b"pasted text"); + } + + #[test] + fn a_focus_report_strips_to_nothing() { + assert_eq!(strip_terminal_replies(b"\x1b[I"), b""); + assert_eq!(strip_terminal_replies(b"\x1b[O"), b""); + } + + #[test] + fn a_secondary_device_attributes_reply_strips_to_nothing() { + assert_eq!(strip_terminal_replies(b"\x1b[>1;10;0c"), b""); + } + + #[test] + fn a_device_status_report_ready_reply_strips_to_nothing() { + assert_eq!(strip_terminal_replies(b"\x1b[0n"), b""); + } + + #[test] + fn empty_input_strips_to_empty() { + assert_eq!(strip_terminal_replies(b""), b""); + } + + // ------------------------------------------------------- ReplyFilter + + // Regression: measured live, a socket read split a reply sequence in + // two -- a lone trailing `c` in one read, a truncated `ESC[?1;2;4` + // missing its closing `c` in the next -- and the bare + // `strip_terminal_replies` (seeing only one buffer at a time) leaked + // both halves as residue, journaling a spurious `outOfBandInput` for + // a storm the filter should have erased entirely. + + #[test] + fn a_reply_sequence_split_across_two_reads_still_strips_to_nothing() { + for split in 1..CAPTURED_CPR_DA_REPLY.len() { + let mut filter = ReplyFilter::new(); + let mut residue = filter.filter(&CAPTURED_CPR_DA_REPLY[..split]); + residue.extend(filter.filter(&CAPTURED_CPR_DA_REPLY[split..])); + assert_eq!( + residue, b"", + "splitting the reply at byte {split} must not leak anything: got {residue:?}" + ); + } + } + + #[test] + fn a_burst_of_replies_split_at_arbitrary_read_boundaries_strips_to_nothing() { + // The exact shape measured live: 146 coalesced replies, chunked + // at a boundary that does not align with any single reply's + // 17-byte length. + let burst: Vec = CAPTURED_CPR_DA_REPLY.repeat(146); + let mut filter = ReplyFilter::new(); + let mut residue = Vec::new(); + for chunk in burst.chunks(7) { + residue.extend(filter.filter(chunk)); + } + assert_eq!( + residue, b"", + "a burst chunked at misaligned boundaries must not leak anything: {residue:?}" + ); + } + + #[test] + fn a_genuine_keystroke_still_survives_the_stream_filter() { + let mut filter = ReplyFilter::new(); + assert_eq!(filter.filter(b"hello"), b"hello"); + } + + #[test] + fn a_keystroke_immediately_after_a_split_reply_is_not_swallowed_with_it() { + let mut filter = ReplyFilter::new(); + let mut residue = filter.filter(&CAPTURED_CPR_DA_REPLY[..10]); + residue.extend(filter.filter(&[&CAPTURED_CPR_DA_REPLY[10..], b"q" as &[u8]].concat())); + assert_eq!(residue, b"q"); + } + + #[test] + fn a_lone_trailing_esc_is_held_back_then_released_once_enough_more_data_arrives() { + let mut filter = ReplyFilter::new(); + // A bare ESC with nothing after it yet: held back, not leaked as + // a spurious single-byte "keystroke". + assert_eq!(filter.filter(b"\x1b"), b""); + // Enough further content arrives without ever completing a + // recognized sequence that the held-back ESC falls out of the + // lookback window -- released as ordinary content, never + // silently lost. This is volume-driven, not time-driven: see + // the next test for the case where no further bytes ever come. + let filler = vec![b'x'; super::MAX_SEQUENCE_LEN]; + let released = filter.filter(&filler); + assert!( + released.starts_with(b"\x1b"), + "the held-back ESC must be released once enough data follows it, not dropped: {released:?}" + ); + } + + // A lone Escape keypress with NO further bytes ever arriving (a + // human presses Escape once -- in a claude TUI, this interrupts the + // current turn -- and then does nothing else) has no volume to age + // it out by the mechanism above. `has_pending`/`take_pending` are + // what a caller uses to release it anyway, on its own idle tick, and + // this is the case that matters: every other test here releases a + // held-back byte by supplying more data, which this one deliberately + // never does. + #[test] + fn a_lone_esc_with_no_further_bytes_is_still_pending_until_the_caller_releases_it_on_its_own_idle_tick() + { + let mut filter = ReplyFilter::new(); + assert_eq!(filter.filter(b"\x1b"), b""); + assert!( + filter.has_pending(), + "a lone ESC with nothing after it must stay held, not be silently dropped" + ); + assert_eq!( + filter.take_pending(), + b"\x1b", + "the caller's own idle-tick release must recover exactly the held-back byte, not drop it" + ); + assert!( + !filter.has_pending(), + "take_pending must actually drain, not just peek" + ); + } +} diff --git a/crates/runtime/tests/lifecycle.rs b/crates/runtime/tests/lifecycle.rs index 7cce2e37..34a1c1da 100644 --- a/crates/runtime/tests/lifecycle.rs +++ b/crates/runtime/tests/lifecycle.rs @@ -1006,3 +1006,223 @@ async fn attach_exits_promptly_after_its_daemon_stops_not_just_the_socket() { reader thread forever" ); } + +/// Like `write_fake_claude_script`, but also emits a CPR (`ESC[6n`) and a +/// DA (`ESC[c`) query on its own stdout every 50ms in the background, +/// starting immediately and continuing for the process's whole lifetime -- +/// simulating a TUI's redraw-driven escape queries with nobody typing. The +/// interval is tighter than any real vendor's redraw cadence so this test +/// stays fast while still producing many query/reply cycles. +fn write_escape_storm_claude_script(scripts_dir: &Path, session_dir: &Path) -> PathBuf { + let script = format!( + r#"#!/bin/sh +if [ "$1" = "--version" ]; then + echo "2.1.241 (Claude Code)" + exit 0 +fi +echo "Welcome to Claude Code!" +SESSION_ID="11111111-1111-4111-8111-000000000099" +TRANSCRIPT="{session_dir}/$SESSION_ID.jsonl" +( while true; do printf '\033[6n\033[c'; sleep 0.05; done ) & +while IFS= read -r line; do + case "$line" in + *"[crew:"*) + printf '%s\n' '{{"type":"user","sessionId":"'"$SESSION_ID"'","timestamp":"2026-01-01T00:00:00Z","message":{{"role":"user","content":"'"$line"'"}}}}' >> "$TRANSCRIPT" + printf '%s\n' '{{"type":"assistant","sessionId":"'"$SESSION_ID"'","timestamp":"2026-01-01T00:00:01Z","message":{{"content":[{{"type":"text","text":"hi from the fixture e2e"}}]}}}}' >> "$TRANSCRIPT" + ;; + esac +done +"#, + session_dir = session_dir.display(), + ); + let path = scripts_dir.join("fake-claude-storm.sh"); + std::fs::write(&path, script).expect("write fake claude storm script"); + let mut perms = std::fs::metadata(&path).unwrap().permissions(); + perms.set_mode(0o755); + std::fs::set_permissions(&path, perms).unwrap(); + path +} + +/// The echo-storm regression test: a vendor TUI's own redraw-driven escape +/// queries, relayed through `crewd attach` to a REAL terminal emulator +/// (tmux, hosting the attach pane exactly as `display/tmux.rs`'s +/// production placement does -- a raw pty pair with nobody driving it +/// does not auto-answer these queries, so this cannot be reproduced any +/// other way), come back as CPR/DA replies on the same socket real +/// keystrokes arrive on. Before the fix, every one of those replies +/// journaled an `outOfBandInput` event and set `needsReconciliation`; +/// measured live before this test existed, idling 20s produced 99 such +/// events. This proves the production filter (`display::terminal_reply`) +/// closes that end to end: idling with nobody typing must journal zero. +/// +/// Skips (visibly) when `tmux` isn't on `PATH` rather than failing -- +/// CI images are not guaranteed to carry it, and a test that fails there +/// is a test that gets deleted. +#[tokio::test] +async fn attach_never_journals_a_vendors_own_terminal_reply_storm() { + if std::process::Command::new("tmux") + .arg("-V") + .output() + .is_err() + { + eprintln!( + "SKIPPING attach_never_journals_a_vendors_own_terminal_reply_storm: `tmux` is not on PATH" + ); + return; + } + + let fixture = Fixture::new(); + let repo = std::fs::canonicalize(fixture.repo_dir()).unwrap(); + + let scripts_dir = tempfile::Builder::new() + .prefix("bat-echostorm-scripts-") + .tempdir_in("/tmp") + .expect("create scripts dir"); + let session_dir = tempfile::Builder::new() + .prefix("bat-echostorm-sess-") + .tempdir_in("/tmp") + .expect("create session dir"); + let script_path = write_escape_storm_claude_script(scripts_dir.path(), session_dir.path()); + let crew_json = scripts_dir.path().join("crew.json"); + std::fs::write( + &crew_json, + serde_json::to_string(&json!({ + "adapters": { + "claude": { + "enabled": true, + "bin": script_path.to_str().unwrap(), + "mode": "tui", + "permissionMode": "default", + "profile": "test", + "sessionDir": session_dir.path().to_str().unwrap() + } + } + })) + .unwrap(), + ) + .unwrap(); + + let (mut server, socket) = DaemonGuard::spawn(&fixture, &crew_json); + let mut client = IpcClient::connect(&socket).await; + let init = client.initialize("omp-1", &repo).await; + assert!(init.get("error").is_none(), "initialize failed: {init:?}"); + + let upsert = client + .call( + 2, + "task/upsert", + json!({ "ownerClientInstanceId": "omp-1", "revision": 1 }), + ) + .await; + let task_id = upsert["result"]["taskId"].as_str().unwrap().to_string(); + let register = client + .call( + 3, + "profile/register", + json!({ + "adapter": "claude", + "model": "test", + "permissionEnvelope": {}, + "startupOptions": { "claude": { "mode": "tui" } }, + "environmentAllowlist": [], + "source": "attach-echo-storm-test" + }), + ) + .await; + let profile_id = register["result"]["profileId"] + .as_str() + .unwrap() + .to_string(); + let wkr = client + .call(4, "worker/create", json!({ "profileId": profile_id })) + .await; + let worker_id = wkr["result"]["workerId"].as_str().unwrap().to_string(); + let submit = client + .call( + 5, + "run/submit", + json!({ "taskId": task_id, "workerId": worker_id, "prompt": "[crew:storm] say hi" }), + ) + .await; + let run_id = submit["result"]["runId"].as_str().unwrap().to_string(); + assert!( + wait_for_run_event(&mut client, &run_id, Duration::from_secs(30)).await, + "run {run_id} must journal at least one event before attaching" + ); + + let tmux_session = format!("crew81-{run_id}"); + let status = std::process::Command::new("tmux") + .args([ + "new-session", + "-d", + "-s", + &tmux_session, + "-x", + "80", + "-y", + "24", + CREWD, + "attach", + &run_id, + "--repo", + repo.to_str().unwrap(), + "--state-dir", + fixture.state_dir().to_str().unwrap(), + ]) + .status() + .expect("start tmux session running crewd attach"); + assert!(status.success(), "tmux new-session must succeed"); + + // Idle: nobody types anything into the pane. The fake vendor's + // background loop keeps querying CPR/DA every 50ms regardless, and + // tmux (the real terminal emulator for this pane) keeps answering on + // its own -- this is the storm, reproduced. + tokio::time::sleep(Duration::from_secs(3)).await; + + // Positive control, asserted BEFORE the real assertion: a scaffold + // that emits nothing at all (a vendor that failed to start, a pane + // that never attached, a timing change that ends the idle window + // before the first burst) would satisfy "zero journaled rows" just + // as well as a working filter -- and certify nothing. Prove the + // storm actually fired first, independent of the journaling path + // under test: capture the pane's own rendered history and count the + // DA reply's fixed parameter string, which only appears there if + // tmux genuinely answered the fake vendor's queries. + let capture = std::process::Command::new("tmux") + .args(["capture-pane", "-p", "-S", "-", "-t", &tmux_session]) + .output() + .expect("capture tmux pane history"); + let captured = String::from_utf8_lossy(&capture.stdout); + let reply_occurrences = captured.matches("?1;2;4c").count(); + const REPLY_FLOOR: usize = 20; + assert!( + reply_occurrences >= REPLY_FLOOR, + "positive control failed: the storm must have produced at least {REPLY_FLOOR} DA replies \ + visible in the tmux pane's history (a scaffold that produced none would pass the real \ + assertion below for the wrong reason) -- got {reply_occurrences} in:\n{captured}" + ); + + let _ = std::process::Command::new("tmux") + .args(["kill-session", "-t", &tmux_session]) + .output(); + + let replay = client + .call(50, "events/replay", json!({ "afterSequence": 0 })) + .await; + let events = replay["result"].as_array().cloned().unwrap_or_default(); + let out_of_band_count = events + .iter() + .filter(|e| { + serde_json::to_string(e) + .unwrap_or_default() + .contains("outOfBandInput") + }) + .count(); + assert_eq!( + out_of_band_count, 0, + "a vendor's own terminal-reply storm (CPR/DA, answered by a real terminal) must never \ + journal an outOfBandInput event -- got {out_of_band_count} in {events:?}" + ); + + let _ = server.shutdown(); +} diff --git a/crates/runtime/tests/tui_adapter.rs b/crates/runtime/tests/tui_adapter.rs index 7b7f9915..1c6cff97 100644 --- a/crates/runtime/tests/tui_adapter.rs +++ b/crates/runtime/tests/tui_adapter.rs @@ -1387,15 +1387,24 @@ async fn out_of_band_input_is_journaled_when_a_viewer_types_into_the_attached_pa assert!(seen, "a viewer keystroke must journal OutOfBandInput"); // The payload itself structurally carries no free text (only - // backend/pane_ref) -- pinned here so the property is not just an - // artifact of the enum's current shape. - let backend_and_ref = sink.payloads().into_iter().find_map(|p| match p { - AdapterEventPayload::OutOfBandInput { backend, pane_ref } => Some((backend, pane_ref)), + // backend/pane_ref/the coalesced count+span) -- pinned here so the + // property is not just an artifact of the enum's current shape. + let payload = sink.payloads().into_iter().find_map(|p| match p { + AdapterEventPayload::OutOfBandInput { + backend, + pane_ref, + input_count, + span_ms, + } => Some((backend, pane_ref, input_count, span_ms)), _ => None, }); - let (backend, pane_ref) = backend_and_ref.expect("checked above"); + let (backend, pane_ref, input_count, _span_ms) = payload.expect("checked above"); assert_eq!(backend, DisplayBackend::Tmux); assert_eq!(pane_ref, "fake-pane-1"); + assert!( + input_count >= 1, + "a coalesced row must count at least the one keystroke that triggered it" + ); adapter.dispose().await.expect("dispose"); harness.shutdown().await; diff --git a/packages/extension/dist/index.js b/packages/extension/dist/index.js index d2a64ff6..bac51119 100644 --- a/packages/extension/dist/index.js +++ b/packages/extension/dist/index.js @@ -8736,7 +8736,15 @@ contents, never an absolute socket or filesystem path.`, additionalProperties: false }, { - description: "A human typed directly into a native pane, bypassing the\nadapter. Sets the run's `RunFlags.needsReconciliation` flag.", + description: `A human typed directly into a native pane, bypassing the +adapter. Sets the run's \`RunFlags.needsReconciliation\` flag. + +Coalesced: one row covers every out-of-band input observed during +one idle window, not one row per keystroke read. Journaled at the +END of the window it describes, so the window's start is this +event's own envelope timestamp minus \`spanMs\` -- no separate start +timestamp is carried, to avoid a second place for the two to +disagree.`, type: "object", properties: { type: { @@ -8754,6 +8762,26 @@ contents, never an absolute socket or filesystem path.`, }, paneRef: { type: "string" + }, + inputCount: { + description: `How many out-of-band inputs this row coalesces. Absent on +rows written before coalescing existed; such a row is exactly +one input, so absence reads as 1, never 0 -- an +\`outOfBandInput\` event means "a human typed", and zero of +them is not a state that can be journaled.`, + type: "integer", + format: "uint64", + minimum: 0, + default: 1 + }, + spanMs: { + description: `Milliseconds between the first and last input this row +coalesces. Absent on rows written before coalescing existed; +such a row is a single input, which spans zero milliseconds.`, + type: "integer", + format: "uint64", + minimum: 0, + default: 0 } }, additionalProperties: false, diff --git a/packages/protocol-ts/schema/crew.schema.json b/packages/protocol-ts/schema/crew.schema.json index b8dde0df..dbdef434 100644 --- a/packages/protocol-ts/schema/crew.schema.json +++ b/packages/protocol-ts/schema/crew.schema.json @@ -1757,7 +1757,7 @@ "additionalProperties": false }, { - "description": "A human typed directly into a native pane, bypassing the\nadapter. Sets the run's `RunFlags.needsReconciliation` flag.", + "description": "A human typed directly into a native pane, bypassing the\nadapter. Sets the run's `RunFlags.needsReconciliation` flag.\n\nCoalesced: one row covers every out-of-band input observed during\none idle window, not one row per keystroke read. Journaled at the\nEND of the window it describes, so the window's start is this\nevent's own envelope timestamp minus `spanMs` -- no separate start\ntimestamp is carried, to avoid a second place for the two to\ndisagree.", "type": "object", "properties": { "type": { @@ -1775,6 +1775,20 @@ }, "paneRef": { "type": "string" + }, + "inputCount": { + "description": "How many out-of-band inputs this row coalesces. Absent on\nrows written before coalescing existed; such a row is exactly\none input, so absence reads as 1, never 0 -- an\n`outOfBandInput` event means \"a human typed\", and zero of\nthem is not a state that can be journaled.", + "type": "integer", + "format": "uint64", + "minimum": 0, + "default": 1 + }, + "spanMs": { + "description": "Milliseconds between the first and last input this row\ncoalesces. Absent on rows written before coalescing existed;\nsuch a row is a single input, which spans zero milliseconds.", + "type": "integer", + "format": "uint64", + "minimum": 0, + "default": 0 } }, "additionalProperties": false, diff --git a/packages/protocol-ts/src/generated/RuntimeEvent.ts b/packages/protocol-ts/src/generated/RuntimeEvent.ts index 0c84d9d9..27391fb7 100644 --- a/packages/protocol-ts/src/generated/RuntimeEvent.ts +++ b/packages/protocol-ts/src/generated/RuntimeEvent.ts @@ -49,7 +49,21 @@ vendorParentRef: string, } } | { "type": "policyViolationRecorded", "payload": { * The vendor-assigned pane identifier only -- never terminal * contents, never an absolute socket or filesystem path. */ -paneRef: string, } } | { "type": "outOfBandInput", "payload": { runId: RunId, backend: DisplayBackend, paneRef: string, } } | { "type": "paneDowngraded", "payload": { runId: RunId, +paneRef: string, } } | { "type": "outOfBandInput", "payload": { runId: RunId, backend: DisplayBackend, paneRef: string, +/** + * How many out-of-band inputs this row coalesces. Absent on + * rows written before coalescing existed; such a row is exactly + * one input, so absence reads as 1, never 0 -- an + * `outOfBandInput` event means "a human typed", and zero of + * them is not a state that can be journaled. + */ +inputCount: number, +/** + * Milliseconds between the first and last input this row + * coalesces. Absent on rows written before coalescing existed; + * such a row is a single input, which spans zero milliseconds. + */ +spanMs: number, } } | { "type": "paneDowngraded", "payload": { runId: RunId, /** * The backend selection actually resolved to, before creation * failed.