From 55d0f09f35de174772d94dafd85aab7c8310e2c8 Mon Sep 17 00:00:00 2001 From: Nathan Herald Date: Tue, 3 Nov 2026 11:35:19 +0100 Subject: [PATCH 1/2] Watch the output during peek --wait, not only the screen (#206) peek --wait read the plain visible screen every 200 ms, as the Node tool does. A marker printed and scrolled away between two reads was never seen. The wait then ran on to its timeout, or, with no timeout, until the session exited and lastLines happened to include the marker. The wait now holds one read-only peek connection for its whole length. The daemon sends that connection the screen and then every byte of output after it. The wait matches the screen, and the visible text of the output as it arrives: - Escape sequences are dropped, also when a chunk boundary splits one. - Only a pattern's length of text is kept across chunks. The 200 ms screen read stays, so text drawn by cursor movement is still found. The watch's own screen is the first look, so a pattern already on screen costs no more connections than before. On a timeout the wait reads the full scrollback once. A pattern found there was printed before the wait began, and a second line says so. The first line and the exit code are Node's. Decision 0019 records the difference. --- crates/pty-client/src/peek.rs | 300 +++++++++++++++++- crates/pty-client/tests/client_peek.rs | 75 +++++ crates/pty/tests/cli_peek_wait.rs | 77 +++++ .../0019-peek-wait-watches-the-output.md | 57 ++++ docs/parity.md | 1 + 5 files changed, 503 insertions(+), 7 deletions(-) create mode 100644 crates/pty/tests/cli_peek_wait.rs create mode 100644 docs/decisions/0019-peek-wait-watches-the-output.md diff --git a/crates/pty-client/src/peek.rs b/crates/pty-client/src/peek.rs index 25ab7dd8..8a57d85f 100644 --- a/crates/pty-client/src/peek.rs +++ b/crates/pty-client/src/peek.rs @@ -311,6 +311,14 @@ pub fn strip_ansi(text: &str) -> String { pub enum PeekWaitError { /// `Timed out after s waiting for "

".` TimedOut { timeout_secs: f64, patterns: String }, + /// The timeout, for a pattern that is in the session's scrollback but was + /// never seen while the wait watched: it was printed before the wait + /// began, or while the output stream was lost (`watched` false). + Missed { + timeout_secs: f64, + patterns: String, + watched: bool, + }, /// `Session "" exited (code ) without matching "

".` plus /// `Last output:` and the indented lines when there are any. Exited { @@ -328,6 +336,24 @@ impl fmt::Display for PeekWaitError { timeout_secs, patterns, } => write!(f, "Timed out after {timeout_secs}s waiting for {patterns}."), + PeekWaitError::Missed { + timeout_secs, + patterns, + watched, + } => { + write!(f, "Timed out after {timeout_secs}s waiting for {patterns}.")?; + if *watched { + write!( + f, + "\nIt is in the scrollback from before the wait began, no longer on screen." + ) + } else { + write!( + f, + "\nIt is in the scrollback, but the wait lost the output stream and did not see it printed." + ) + } + } PeekWaitError::Exited { name, exit_code, @@ -368,12 +394,20 @@ pub fn describe_patterns(patterns: &[String]) -> String { /// Poll interval of `peek --wait`. pub const PEEK_WAIT_INTERVAL: Duration = Duration::from_millis(200); -/// `peek --wait`: poll the plain screen every 200 ms until any pattern is a -/// substring. Returns the text to print (the plain screen, or a fresh ANSI +/// `peek --wait`: wait until any pattern is a substring of what the session +/// shows. Returns the text to print (the plain screen, or a fresh ANSI /// screen when `plain` is false; the CLI appends `"\n"`). When the session /// has exited, `lastLines` from the metadata is matched instead. /// A `timeout_secs` that is not a finite positive number waits forever. /// +/// Two looks, and either one ends the wait. The plain screen is read every +/// 200 ms, as the Node tool does, which finds text drawn anywhere on it. The +/// output is also watched as it arrives, on one read-only peek connection, +/// which finds a pattern printed and scrolled away between two reads of the +/// screen. Reading the screen alone missed that, and the wait ran on to the +/// timeout or to the session's exit. On a timeout the full scrollback tells +/// such a miss apart from a pattern that never appeared. +/// /// node: tests/peek-wait.test.ts:111-188 pub fn peek_wait( name: &str, @@ -393,15 +427,44 @@ pub fn peek_wait( }; let matches_any = |text: &str| patterns.iter().any(|p| text.contains(p.as_str())); let desc = describe_patterns(patterns); + // The watch's own screen is the first look, so a pattern already on + // screen costs no more connections than it did. + let mut watch = OutputWatch::open(name); + let mut watched = watch.is_some(); + let mut next_look = if watched { + start + PEEK_WAIT_INTERVAL + } else { + start + }; + let mut last_screen = String::new(); loop { if let Some(t) = timeout && start.elapsed() > t { - return Err(PeekWaitError::TimedOut { - timeout_secs, - patterns: desc, - }); + // Output that arrived since the last look still counts. + if let Some(w) = watch.as_mut() + && w.wait_until(Instant::now(), patterns) == Watched::Seen + { + return Ok(screen_now(name, plain, &last_screen, &w.screen)); + } + return Err(timed_out(name, patterns, timeout_secs, desc, watched)); + } + if let Some(w) = watch.as_mut() { + match w.wait_until(next_look, patterns) { + Watched::Seen => return Ok(screen_now(name, plain, &last_screen, &w.screen)), + Watched::Quiet => {} + Watched::Lost => { + watch = None; + watched = false; + } + } + } else { + std::thread::sleep(next_look.saturating_duration_since(Instant::now())); + } + if Instant::now() < next_look { + continue; } + next_look = Instant::now() + PEEK_WAIT_INTERVAL; match peek_screen( name, PeekScreenOptions { @@ -428,6 +491,7 @@ pub fn peek_wait( // plain screen, which did match. return Ok(screen); } + last_screen = screen; } Err(_) => { // Session might have exited — check metadata for lastLines. @@ -449,6 +513,228 @@ pub fn peek_wait( // No exitedAt — might be a transient connection error, retry. } } - std::thread::sleep(PEEK_WAIT_INTERVAL); + } +} + +/// The screen to print once the watch saw a pattern. It may have scrolled +/// away by now; the wait was satisfied when it was printed. +fn screen_now(name: &str, plain: bool, last_screen: &str, watch_screen: &str) -> String { + peek_screen(name, PeekScreenOptions { plain, full: false }).unwrap_or_else(|_| { + if last_screen.is_empty() { + watch_screen + } else { + last_screen + } + .to_string() + }) +} + +/// The timeout, telling a pattern that is in the scrollback, so was printed +/// before the wait could see it, apart from one that never appeared. +fn timed_out( + name: &str, + patterns: &[String], + timeout_secs: f64, + patterns_text: String, + watched: bool, +) -> PeekWaitError { + let in_scrollback = peek_screen( + name, + PeekScreenOptions { + plain: true, + full: true, + }, + ) + .is_ok_and(|text| patterns.iter().any(|p| text.contains(p.as_str()))); + if in_scrollback { + PeekWaitError::Missed { + timeout_secs, + patterns: patterns_text, + watched, + } + } else { + PeekWaitError::TimedOut { + timeout_secs, + patterns: patterns_text, + } + } +} + +/// What the output watch saw before its deadline. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +enum Watched { + Seen, + Quiet, + /// The connection ended or failed; the wait goes on reading the screen. + Lost, +} + +/// A read-only peek connection held open for a whole `peek --wait`. The +/// daemon sends it the screen and then every byte of output after it, so +/// nothing printed while it is open goes unseen. +struct OutputWatch { + socket: UnixStream, + reader: PacketReader, + text: VisibleText, + /// The plain screen the connection started with. + screen: String, +} + +impl OutputWatch { + fn open(name: &str) -> Option { + let mut socket = connect_session(name).ok()?; + socket.write_all(&encode_peek(true, false)).ok()?; + Some(OutputWatch { + socket, + reader: PacketReader::new(), + text: VisibleText::default(), + screen: String::new(), + }) + } + + /// Read what arrives until `until`, stopping as soon as a pattern shows. + fn wait_until(&mut self, until: Instant, patterns: &[String]) -> Watched { + use std::os::fd::AsRawFd; + let mut buf = [0u8; 16384]; + loop { + let left = until.saturating_duration_since(Instant::now()); + let mut fds = [libc::pollfd { + fd: self.socket.as_raw_fd(), + events: libc::POLLIN, + revents: 0, + }]; + match poll(&mut fds, left.as_millis().min(i32::MAX as u128) as i32) { + Ok(0) => return Watched::Quiet, + Ok(_) => {} + Err(_) => return Watched::Lost, + } + let n = match self.socket.read(&mut buf) { + Ok(0) | Err(_) => return Watched::Lost, + Ok(n) => n, + }; + let Ok(packets) = self.reader.feed(&buf[..n]) else { + return Watched::Lost; + }; + for p in packets { + match p.type_ { + MessageType::Screen => { + self.screen = String::from_utf8_lossy(&p.payload).into_owned(); + if contains_any(&p.payload, patterns) { + return Watched::Seen; + } + } + MessageType::Data => { + if self.text.feed(&p.payload, patterns) { + return Watched::Seen; + } + } + MessageType::Exit | MessageType::ConnectionError => return Watched::Lost, + _ => {} + } + } + } + } +} + +fn contains_any(haystack: &[u8], patterns: &[String]) -> bool { + patterns.iter().any(|p| { + let p = p.as_bytes(); + p.is_empty() || haystack.windows(p.len()).any(|w| w == p) + }) +} + +/// The visible text of an output stream. Escape sequences are dropped, also +/// when a chunk boundary splits one, and the newest text is kept only as +/// long as a pattern could still end in the next chunk. +#[derive(Default)] +struct VisibleText { + state: Escape, + tail: Vec, +} + +#[derive(Default, Clone, Copy, PartialEq, Eq)] +enum Escape { + #[default] + Ground, + Esc, + /// `ESC` and intermediates, waiting for the final byte. + Intermediate, + Csi, + /// OSC, DCS, SOS, PM or APC: a string ended by BEL or ST. + Text, + TextEsc, +} + +impl VisibleText { + /// Add `chunk` and say whether any pattern now appears. + fn feed(&mut self, chunk: &[u8], patterns: &[String]) -> bool { + for &b in chunk { + self.state = match (self.state, b) { + (Escape::Ground, 0x1b) => Escape::Esc, + (Escape::Ground, _) => { + self.tail.push(b); + Escape::Ground + } + (Escape::Esc, b'[') => Escape::Csi, + (Escape::Esc, b']' | b'P' | b'X' | b'^' | b'_') => Escape::Text, + (Escape::Esc | Escape::Intermediate, 0x20..=0x2f) => Escape::Intermediate, + (Escape::Esc | Escape::Intermediate, _) => Escape::Ground, + (Escape::Csi, 0x40..=0x7e) => Escape::Ground, + (Escape::Csi, _) => Escape::Csi, + (Escape::Text, 0x07) => Escape::Ground, + (Escape::Text, 0x1b) => Escape::TextEsc, + (Escape::Text, _) => Escape::Text, + (Escape::TextEsc, _) => Escape::Ground, + }; + } + let found = contains_any(&self.tail, patterns); + let keep = patterns + .iter() + .map(String::len) + .max() + .unwrap_or(0) + .saturating_sub(1); + let drop = self.tail.len().saturating_sub(keep); + self.tail.drain(..drop); + found + } +} + +#[cfg(test)] +mod visible_text_tests { + use super::VisibleText; + + fn feed_all(chunks: &[&[u8]], pattern: &str) -> bool { + let mut text = VisibleText::default(); + let patterns = [pattern.to_string()]; + chunks.iter().any(|chunk| text.feed(chunk, &patterns)) + } + + #[test] + fn a_pattern_split_across_chunks_and_styles_is_seen() { + assert!(feed_all( + &[b"\x1b[1mEND ", b"0", b"\x1b[0m04\r\n"], + "END 004" + )); + assert!(feed_all(&[b"END 0\x1b", b"[32", b"m04"], "END 004")); + } + + #[test] + fn escape_strings_and_their_payloads_are_not_text() { + // A window title, a DCS and a charset designation carry no text. + assert!(!feed_all(&[b"\x1b]0;END 004\x07"], "END 004")); + assert!(!feed_all(&[b"\x1b]2;END ", b"004\x1b\\"], "END 004")); + assert!(!feed_all(&[b"\x1bPEND 004\x1b\\"], "END 004")); + assert!(feed_all(&[b"\x1b(BEND 004"], "END 004")); + } + + #[test] + fn only_a_pattern_length_of_text_is_kept() { + let mut text = VisibleText::default(); + let patterns = ["END 004".to_string()]; + assert!(!text.feed(&[b'x'; 10_000], &patterns)); + assert_eq!(text.tail.len(), "END 004".len() - 1); + assert!(!text.feed(b"END 00", &patterns)); + assert!(text.feed(b"4", &patterns)); } } diff --git a/crates/pty-client/tests/client_peek.rs b/crates/pty-client/tests/client_peek.rs index 8f601e18..d0e98261 100644 --- a/crates/pty-client/tests/client_peek.rs +++ b/crates/pty-client/tests/client_peek.rs @@ -279,6 +279,81 @@ fn peek_wait_times_out_with_the_exact_text() { ); } +/// The wait's first connection is its output watch. The marker arrives there +/// in pieces, between styles, and no screen any connection is sent ever +/// shows it, as when it is printed and scrolled away between two looks. +#[test] +fn peek_wait_sees_a_marker_that_only_the_output_carried() { + let d = FakeDaemon::bind("stream"); + let listener = d.listener.try_clone().unwrap(); + std::thread::spawn(move || { + use std::io::Write; + let (mut watch, _) = listener.accept().unwrap(); + let first = packets(&read_chunk(&mut watch)); + assert_eq!(decode_peek(&first[0].payload), (true, false)); + std::thread::spawn(move || { + watch.write_all(&encode_screen(b"before")).unwrap(); + std::thread::sleep(Duration::from_millis(500)); + watch.write_all(&encode_data(b"\x1b[1mEND ")).unwrap(); + watch + .write_all(&encode_data(b"004\x1b[0m\r\nmore\r\n")) + .unwrap(); + let _ = std::io::Read::read(&mut watch, &mut [0u8; 64]); + }); + // Every other connection is a look at the screen. + while let Ok((mut s, _)) = listener.accept() { + let _ = read_chunk(&mut s); + let _ = s.write_all(&encode_screen(b"after")); + } + }); + let started = std::time::Instant::now(); + let got = peek_wait(&d.name, &["END 004".into()], 5.0, true).unwrap(); + assert_eq!(got, "after"); + assert!( + started.elapsed() < Duration::from_secs(2), + "{:?}", + started.elapsed() + ); +} + +/// A pattern in the scrollback but never seen while waiting was printed +/// before the wait began; one that is nowhere never appeared. +#[test] +fn peek_wait_tells_a_missed_pattern_from_one_that_never_appeared() { + let d = FakeDaemon::bind("missed"); + let listener = d.listener.try_clone().unwrap(); + std::thread::spawn(move || { + use std::io::Write; + let (mut watch, _) = listener.accept().unwrap(); + let _ = read_chunk(&mut watch); + watch.write_all(&encode_screen(b"on screen")).unwrap(); + std::thread::spawn(move || { + let _ = std::io::Read::read(&mut watch, &mut [0u8; 64]); + }); + while let Ok((mut s, _)) = listener.accept() { + let first = packets(&read_chunk(&mut s)); + let (_, full) = decode_peek(&first[0].payload); + let screen: &[u8] = if full { + b"EARLY\non screen" + } else { + b"on screen" + }; + let _ = s.write_all(&encode_screen(screen)); + } + }); + let err = peek_wait(&d.name, &["EARLY".into()], 0.5, true).unwrap_err(); + assert_eq!( + err.to_string(), + "Timed out after 0.5s waiting for \"EARLY\".\n\ + It is in the scrollback from before the wait began, no longer on screen." + ); + let err = peek_wait(&d.name, &["NEVER".into()], 0.5, true).unwrap_err(); + assert_eq!( + err.to_string(), + "Timed out after 0.5s waiting for \"NEVER\"." + ); +} + fn write_exited_metadata(name: &str, last_lines: &[&str], exit_code: Option) { let json = serde_json::json!({ "command": "sh", diff --git a/crates/pty/tests/cli_peek_wait.rs b/crates/pty/tests/cli_peek_wait.rs new file mode 100644 index 00000000..bc955cf9 --- /dev/null +++ b/crates/pty/tests/cli_peek_wait.rs @@ -0,0 +1,77 @@ +//! `peek --wait` against a real session: a marker printed while the wait +//! runs satisfies it even when the same write scrolls it off the screen, and +//! on a timeout a marker from before the wait is told apart from one that +//! never appeared. + +mod cli_common; + +use std::os::unix::net::UnixStream; +use std::time::{Duration, Instant}; + +use cli_common::{Rig, wait_until}; + +/// One write puts the marker and 200 lines after it on the terminal, so no +/// look at the screen, however timed, ever shows the marker. +const MARKER_THEN_SCROLL: &str = r#"printf 'END 004\n%s\n' "$(seq 1 200)""#; + +fn start(rig: &Rig, name: &str, script: &str) { + rig.ok(&["run", "-d", "--id", name, "--", "sh", "-c", script]); + wait_until("socket up", || { + UnixStream::connect(rig.path(&format!("{name}.sock"))).is_ok() + }); +} + +fn scrolled_away(rig: &Rig, name: &str) -> bool { + let screen = rig.ok(&["peek", "--plain", name]).stdout; + let full = rig.ok(&["peek", "--plain", "--full", name]).stdout; + !screen.contains("END 004") && full.contains("END 004") +} + +#[test] +fn a_marker_scrolled_away_while_waiting_satisfies_the_wait() { + let rig = Rig::new(); + let go = rig.scratch.join("go"); + let script = format!( + "while [ ! -e '{}' ]; do sleep 0.02; done; {MARKER_THEN_SCROLL}; exec cat", + go.display() + ); + start(&rig, "scroll", &script); + let opener = { + let go = go.clone(); + std::thread::spawn(move || { + std::thread::sleep(Duration::from_millis(500)); + std::fs::write(&go, b"").unwrap(); + }) + }; + let started = Instant::now(); + let out = rig.run(&["peek", "--plain", "--wait", "END 004", "-t", "10", "scroll"]); + opener.join().unwrap(); + assert_eq!(out.code, 0, "{out:?}"); + assert!( + started.elapsed() < Duration::from_secs(5), + "{:?}", + started.elapsed() + ); + assert!(scrolled_away(&rig, "scroll")); +} + +#[test] +fn a_marker_from_before_the_wait_is_reported_as_missed() { + let rig = Rig::new(); + start(&rig, "early", &format!("{MARKER_THEN_SCROLL}; exec cat")); + wait_until("the marker scrolled away", || scrolled_away(&rig, "early")); + + let out = rig.run(&["peek", "--plain", "--wait", "END 004", "-t", "1", "early"]); + assert_eq!(out.code, 1, "{out:?}"); + assert_eq!( + out.stderr.trim_end(), + "Timed out after 1s waiting for \"END 004\".\n\ + It is in the scrollback from before the wait began, no longer on screen." + ); + let out = rig.run(&["peek", "--plain", "--wait", "NEVER", "-t", "1", "early"]); + assert_eq!(out.code, 1, "{out:?}"); + assert_eq!( + out.stderr.trim_end(), + "Timed out after 1s waiting for \"NEVER\"." + ); +} diff --git a/docs/decisions/0019-peek-wait-watches-the-output.md b/docs/decisions/0019-peek-wait-watches-the-output.md new file mode 100644 index 00000000..845ef31e --- /dev/null +++ b/docs/decisions/0019-peek-wait-watches-the-output.md @@ -0,0 +1,57 @@ +# 0019 — `peek --wait` watches the output, not only the screen + +**Status:** accepted + +**Node behavior.** `cmdPeekWait` (`src/cli.ts`) reads the plain visible screen +every 200 ms and stops when a pattern is a substring of it. A pattern that is +printed and then scrolled off the screen between two reads is never seen. The +wait runs on to its timeout, or, with no timeout, until the session exits and +the saved `lastLines` happen to include the pattern. A timeout reads the same +whether the pattern was missed or never printed. + +**Rust behavior.** The 200 ms screen read stays. Alongside it, `peek --wait` +holds one read-only peek connection for the whole wait. The daemon sends that +connection the screen and then every byte of output after it. The wait +matches the pattern against that screen, and against the output's visible +text as it arrives: +- Escape sequences (CSI, OSC, DCS and the like) are dropped, also when a chunk + boundary splits one. +- A pattern split across two chunks still matches. + +On a timeout the wait reads the full scrollback once. If the pattern is there, +it was printed before the wait began, and the error says so on a second line +after Node's text: + +``` +Timed out after 1s waiting for "END 004". +It is in the scrollback from before the wait began, no longer on screen. +``` + +**Why.** A marker printed while someone is waiting for it should end the +wait. Losing it to the sampling interval made a finite wait end only at its +bound, or at the session's exit, which reads as a hung command. Telling a +missed marker from an absent one tells the caller whether to look earlier in +the output or to keep waiting. + +**Client effect.** +- A wait returns as soon as the pattern is printed, even when the same write + scrolls it away. What it prints is the screen at that moment, which may no + longer show the pattern. +- While the wait runs, the session counts one more read-only client, as it + does during `peek -f`. +- A wait that matches what is already on screen opens no more connections + than before: the watch's own screen is the first look. +- Exit codes and the first line of every error are Node's. + +**Test.** +- `crates/pty/tests/cli_peek_wait.rs` runs against a real session: a marker + printed and scrolled away by one write while the wait runs, and a marker + from before the wait next to a pattern that never appeared. +- `crates/pty-client/tests/client_peek.rs` covers the same two cases against a + fake daemon, with the marker split across output chunks and styles. +- The visible-text scanner's unit tests are in `crates/pty-client/src/peek.rs`. + +All four behavior tests fail on the screen-only wait. There is no gated Node +half: the Node pty is not installed where these ran, and it is deprecated. + +**Migration / negotiation.** None. diff --git a/docs/parity.md b/docs/parity.md index 70b47278..2a891d9b 100644 --- a/docs/parity.md +++ b/docs/parity.md @@ -380,6 +380,7 @@ Decided on 2026-08-29. Each row records the decision. | Registry files written owner-only (0600), temp files created 0600 at open | S | Kept as an extension. Records persist `extraEnv`/`sessionEnv` values; the file mode is set by the creating open (no create-then-chmod window). An existing session root keeps the mode its owner gave it — even a symlinked one — while a root this code creates is 0700. | | `up`/`down` and `pty.toml` | S | Kept. Already ported; the binding rule needs the tag pair. | | `queryStats` waiting out its 2 s timeout on a daemon that closes without STATUS, and `peek -f` hanging on a plain close | S | Not reproduced, on purpose. Both end promptly instead. Deliberate improvements, not gaps — accepted, decision 0006. | +| `peek --wait` missing a pattern that scrolls off between two 200 ms screen reads | S | Not reproduced, on purpose. The wait also watches the output stream, and a timeout says when the pattern is in the scrollback from before the wait. Accepted, decision 0019. | ## 12c. What differs because the kernel differs From 7ee880e59813d30689fccb84d34e4c38026f1722 Mon Sep 17 00:00:00 2001 From: Nathan Herald Date: Tue, 3 Nov 2026 11:49:01 +0100 Subject: [PATCH 2/2] Bound the peek --wait watch by its deadline, and join text only across styles Two review findings on the output watch: - wait_until applied its deadline only to poll. Under output that never pauses, poll reports ready every time, so the read went on past the deadline. The wait then reached neither its screen read nor its timeout. It now returns once the deadline has passed, after at most one more chunk. - The scanner dropped every CSI and joined the text either side, so "END \e[2;1H004" matched "END 004" although the terminal never showed it. Text now joins only across SGR, a charset designation or an escape string. Every other CSI and the single-byte escapes reset the carried text, after checking it for a match. Text drawn that way is left to the screen read. Tests: - A fake daemon that floods the watch: a 1 s wait times out in about 1 s. - A unit test: past its deadline, the watch reads one chunk of a full socket and returns. - Negative scanner cases for cursor moves. --- crates/pty-client/src/peek.rs | 107 +++++++++++++++--- crates/pty-client/tests/client_peek.rs | 39 +++++++ .../0019-peek-wait-watches-the-output.md | 20 +++- 3 files changed, 149 insertions(+), 17 deletions(-) diff --git a/crates/pty-client/src/peek.rs b/crates/pty-client/src/peek.rs index 8a57d85f..3f204542 100644 --- a/crates/pty-client/src/peek.rs +++ b/crates/pty-client/src/peek.rs @@ -593,6 +593,8 @@ impl OutputWatch { } /// Read what arrives until `until`, stopping as soon as a pattern shows. + /// It returns by `until` even while output keeps coming, so the caller + /// still reaches its screen look and its timeout. fn wait_until(&mut self, until: Instant, patterns: &[String]) -> Watched { use std::os::fd::AsRawFd; let mut buf = [0u8; 16384]; @@ -632,6 +634,11 @@ impl OutputWatch { _ => {} } } + // Under output that never pauses, poll reports ready every time, + // and only this check ends the read. + if Instant::now() >= until { + return Watched::Quiet; + } } } } @@ -667,27 +674,42 @@ enum Escape { impl VisibleText { /// Add `chunk` and say whether any pattern now appears. + /// + /// Text is joined across a style change, a charset designation or an + /// escape string, which leave the cursor where it was. It is not joined + /// across anything that can move the cursor or change the text around + /// it: every other CSI, and the single-byte escapes such as `ESC 8`. + /// Text drawn that way is left to the screen read. fn feed(&mut self, chunk: &[u8], patterns: &[String]) -> bool { + let mut found = false; for &b in chunk { - self.state = match (self.state, b) { - (Escape::Ground, 0x1b) => Escape::Esc, + let (state, breaks) = match (self.state, b) { + (Escape::Ground, 0x1b) => (Escape::Esc, false), (Escape::Ground, _) => { self.tail.push(b); - Escape::Ground + (Escape::Ground, false) } - (Escape::Esc, b'[') => Escape::Csi, - (Escape::Esc, b']' | b'P' | b'X' | b'^' | b'_') => Escape::Text, - (Escape::Esc | Escape::Intermediate, 0x20..=0x2f) => Escape::Intermediate, - (Escape::Esc | Escape::Intermediate, _) => Escape::Ground, - (Escape::Csi, 0x40..=0x7e) => Escape::Ground, - (Escape::Csi, _) => Escape::Csi, - (Escape::Text, 0x07) => Escape::Ground, - (Escape::Text, 0x1b) => Escape::TextEsc, - (Escape::Text, _) => Escape::Text, - (Escape::TextEsc, _) => Escape::Ground, + (Escape::Esc, b'[') => (Escape::Csi, false), + (Escape::Esc, b']' | b'P' | b'X' | b'^' | b'_') => (Escape::Text, false), + (Escape::Esc | Escape::Intermediate, 0x20..=0x2f) => (Escape::Intermediate, false), + (Escape::Intermediate, _) => (Escape::Ground, false), + (Escape::Esc, _) => (Escape::Ground, true), + (Escape::Csi, b'm') => (Escape::Ground, false), + (Escape::Csi, 0x40..=0x7e) => (Escape::Ground, true), + (Escape::Csi, _) => (Escape::Csi, false), + (Escape::Text, 0x07) => (Escape::Ground, false), + (Escape::Text, 0x1b) => (Escape::TextEsc, false), + (Escape::Text, _) => (Escape::Text, false), + (Escape::TextEsc, _) => (Escape::Ground, false), }; + self.state = state; + if breaks { + // A pattern completed before the move still counts. + found |= contains_any(&self.tail, patterns); + self.tail.clear(); + } } - let found = contains_any(&self.tail, patterns); + found |= contains_any(&self.tail, patterns); let keep = patterns .iter() .map(String::len) @@ -728,6 +750,15 @@ mod visible_text_tests { assert!(feed_all(&[b"\x1b(BEND 004"], "END 004")); } + #[test] + fn text_either_side_of_a_cursor_move_is_not_joined() { + assert!(!feed_all(&[b"END \x1b[2;1H004"], "END 004")); + assert!(!feed_all(&[b"END \x1b[1A", b"004"], "END 004")); + assert!(!feed_all(&[b"END \x1b8004"], "END 004")); + // A pattern completed before the move still counts. + assert!(feed_all(&[b"END 004\x1b[2J"], "END 004")); + } + #[test] fn only_a_pattern_length_of_text_is_kept() { let mut text = VisibleText::default(); @@ -738,3 +769,51 @@ mod visible_text_tests { assert!(text.feed(b"4", &patterns)); } } + +#[cfg(test)] +mod output_watch_tests { + use super::*; + use pty_core::protocol::encode_data; + + /// Once its deadline has passed the watch reads one chunk and returns, + /// however much output is waiting, so a flood cannot hold the wait. + #[cfg(target_os = "linux")] + #[test] + fn past_its_deadline_the_watch_reads_one_chunk_and_returns() { + let (client, mut daemon) = UnixStream::pair().unwrap(); + daemon.set_nonblocking(true).unwrap(); + let packet = encode_data(&[b'y'; 1000]); + let mut written = 0; + while daemon.write_all(&packet).is_ok() { + written += packet.len(); + } + assert!( + written > 4 * 16384, + "only {written} bytes fit in the socket" + ); + let mut watch = OutputWatch { + socket: client, + reader: PacketReader::new(), + text: VisibleText::default(), + screen: String::new(), + }; + assert_eq!( + watch.wait_until(Instant::now(), &["NEVER".to_string()]), + Watched::Quiet + ); + watch.socket.set_nonblocking(true).unwrap(); + let mut left = 0; + let mut buf = [0u8; 65536]; + while let Ok(n) = watch.socket.read(&mut buf) { + if n == 0 { + break; + } + left += n; + } + assert!( + left >= written - 16384, + "read {} of {written} bytes", + written - left + ); + } +} diff --git a/crates/pty-client/tests/client_peek.rs b/crates/pty-client/tests/client_peek.rs index d0e98261..e0d9dc13 100644 --- a/crates/pty-client/tests/client_peek.rs +++ b/crates/pty-client/tests/client_peek.rs @@ -354,6 +354,45 @@ fn peek_wait_tells_a_missed_pattern_from_one_that_never_appeared() { ); } +/// Output that never pauses, like `yes`, must not hold the wait past its +/// bound: the watch keeps finding data ready, and the wait has to stop +/// reading to look at the screen and the clock. +#[test] +fn peek_wait_keeps_its_bound_under_output_that_never_pauses() { + let d = FakeDaemon::bind("flood"); + let listener = d.listener.try_clone().unwrap(); + std::thread::spawn(move || { + use std::io::Write; + let (mut watch, _) = listener.accept().unwrap(); + let _ = read_chunk(&mut watch); + std::thread::spawn(move || { + let flood = encode_data(&b"y\r\n".repeat(64 * 1024)); + if watch.write_all(&encode_screen(b"y")).is_ok() { + while watch.write_all(&flood).is_ok() {} + } + }); + while let Ok((mut s, _)) = listener.accept() { + let _ = read_chunk(&mut s); + let _ = s.write_all(&encode_screen(b"y")); + } + }); + let (tx, rx) = std::sync::mpsc::channel(); + let name = d.name.clone(); + std::thread::spawn(move || { + let started = std::time::Instant::now(); + let result = peek_wait(&name, &["NEVER".into()], 1.0, true); + let _ = tx.send((result, started.elapsed())); + }); + let (result, elapsed) = rx + .recv_timeout(Duration::from_secs(10)) + .expect("the wait ran past its 1 s bound"); + assert_eq!( + result.unwrap_err().to_string(), + "Timed out after 1s waiting for \"NEVER\"." + ); + assert!(elapsed < Duration::from_millis(2500), "{elapsed:?}"); +} + fn write_exited_metadata(name: &str, last_lines: &[&str], exit_code: Option) { let json = serde_json::json!({ "command": "sh", diff --git a/docs/decisions/0019-peek-wait-watches-the-output.md b/docs/decisions/0019-peek-wait-watches-the-output.md index 845ef31e..bf0e3fa5 100644 --- a/docs/decisions/0019-peek-wait-watches-the-output.md +++ b/docs/decisions/0019-peek-wait-watches-the-output.md @@ -16,7 +16,15 @@ matches the pattern against that screen, and against the output's visible text as it arrives: - Escape sequences (CSI, OSC, DCS and the like) are dropped, also when a chunk boundary splits one. -- A pattern split across two chunks still matches. +- A pattern split across two chunks still matches, and so does one split by a + style change. +- Text either side of anything that can move the cursor is not joined: every + CSI but SGR, and the single-byte escapes such as `ESC 8`. `END \e[2;1H004` + never formed "END 004" on the terminal, so it does not match. Text drawn + that way is left to the screen read. +- After its look is due, the watch reads at most one more chunk. A session + that prints without pause cannot hold the wait past its screen read or its + timeout. On a timeout the wait reads the full scrollback once. If the pattern is there, it was printed before the wait began, and the error says so on a second line @@ -48,8 +56,14 @@ the output or to keep waiting. printed and scrolled away by one write while the wait runs, and a marker from before the wait next to a pattern that never appeared. - `crates/pty-client/tests/client_peek.rs` covers the same two cases against a - fake daemon, with the marker split across output chunks and styles. -- The visible-text scanner's unit tests are in `crates/pty-client/src/peek.rs`. + fake daemon, with the marker split across output chunks and styles. It also + checks that a 1 s wait on output that never pauses still times out in about + 1 s. +- `crates/pty-client/src/peek.rs` holds the unit tests: + - the visible-text scanner, including that text either side of a cursor + move is not joined; + - that a watch past its deadline reads one chunk of a full socket and + returns. All four behavior tests fail on the screen-only wait. There is no gated Node half: the Node pty is not installed where these ran, and it is deprecated.