diff --git a/README.md b/README.md index 52e96796..b99a221b 100644 --- a/README.md +++ b/README.md @@ -106,10 +106,19 @@ returns immediately (exit status 0), even if its event log was removed. Other event types wait for a new matching event. A missing session returns a not-found error (exit status 1); a vanished target with no recorded exit also fails promptly, including a launcher that never started. A session removed -while waiting without an observed matching event returns 1. The timeout is an independent deadline -and returns 1 even when no filesystem events arrive. Followers ignore read-only -filesystem notifications and coalesce change notifications, avoiding feedback -from their own registry reads. +while waiting without an observed matching event returns 1. So does any wait +whose daemon dies without recording an exit, before or after the wait starts; +a named follow ends there with 0. A record no daemon has claimed yet keeps +other waits waiting, since its launcher may still start it. The timeout is an +independent deadline and returns 1 even when no filesystem events arrive. +Options may follow the session reference, and any other argument is an error +(exit status 1) rather than silently dropping the options after it. + +Followers ignore read-only filesystem notifications and coalesce change +notifications, avoiding feedback from their own registry reads. Every session +writes into the one registry directory, so a named follower wakes only for its +own sessions' logs and metadata, and `--all` only for logs; the 250 ms poll +covers anything a notification misses. Cursor visibility and window titles are live terminal state, not durable event history: TUI redraws and title spinners can change them dozens of times per diff --git a/crates/pty-core/src/events/follow.rs b/crates/pty-core/src/events/follow.rs index f45b91d4..803c62a1 100644 --- a/crates/pty-core/src/events/follow.rs +++ b/crates/pty-core/src/events/follow.rs @@ -6,11 +6,16 @@ //! //! Change detection is the `notify` crate on the registry directory plus a //! poll every 250 ms, so delivery is deterministic even when the watcher -//! misses or coalesces an event, or is still starting. +//! misses or coalesces an event, or is still starting. A notification wakes +//! the follower only for the files it reads. +//! +//! A named source ends when its session exits, its registry entry is +//! removed, or its daemon vanishes without recording an exit. //! //! node: src/events.ts:430-546 -use std::collections::BTreeMap; +use std::collections::{BTreeMap, BTreeSet}; +use std::ffi::{OsStr, OsString}; use std::path::{Path, PathBuf}; use std::sync::Arc; use std::sync::atomic::{AtomicBool, Ordering}; @@ -23,7 +28,7 @@ use notify::{EventKind, RecursiveMode, Watcher}; use super::Event; use crate::registry; -use crate::registry::root::{events_path, metadata_path, session_dir}; +use crate::registry::root::{events_path, metadata_path, pid_path, session_dir}; /// The poll fallback interval. pub const DEFAULT_POLL_INTERVAL: Duration = Duration::from_millis(250); @@ -66,6 +71,8 @@ impl FollowerOptions { /// A running follower; `stop` (or drop) ends the background thread. pub struct EventFollower { stop: Arc, + // Interrupts the poll wait, so a stop does not wait out the interval. + wake: SyncSender<()>, handle: Option>, } @@ -82,13 +89,18 @@ impl EventFollower { let stop = Arc::new(AtomicBool::new(false)); let stop_flag = stop.clone(); let (ready_tx, ready_rx) = channel(); + // A bounded signal coalesces bursts without an unbounded drain that + // can prevent shutdown while another process keeps changing the + // directory. + let (wake_tx, wake_rx) = sync_channel(1); + let wake = wake_tx.clone(); let handle = std::thread::Builder::new() .name("events-follow".to_string()) - .spawn(move || run(options, on_event, stop_flag, ready_tx)) + .spawn(move || run(options, on_event, stop_flag, ready_tx, wake_tx, wake_rx)) .ok(); // Disconnected when the thread could not start: nothing to wait for. let _ = ready_rx.recv(); - EventFollower { stop, handle } + EventFollower { stop, wake, handle } } /// Start following and receive events on a channel. @@ -105,6 +117,7 @@ impl EventFollower { /// node: src/events.ts:451-458 pub fn stop(&mut self) { self.stop.store(true, Ordering::SeqCst); + let _ = self.wake.try_send(()); if let Some(h) = self.handle.take() { let _ = h.join(); } @@ -142,6 +155,39 @@ fn name_of(file_name: &str) -> Option<&str> { file_name.strip_suffix(EVENTS_SUFFIX) } +/// The registry files a follower reads. Every session writes into the one +/// watched directory, so a named follower ignores the other sessions' files. +enum Interest { + /// `--all`: every session's log. + Logs, + /// Named sessions: their logs and metadata. + Files(BTreeSet), +} + +impl Interest { + fn new(names: Option<&[String]>) -> Self { + let Some(names) = names else { + return Interest::Logs; + }; + Interest::Files( + names + .iter() + .flat_map(|name| [events_path(name), metadata_path(name)]) + .filter_map(|path| path.file_name().map(OsStr::to_os_string)) + .collect(), + ) + } + + // A notification without paths names nothing, so it may concern anything. + fn covers(&self, event: ¬ify::Event) -> bool { + event.paths.is_empty() + || event.paths.iter().filter_map(|path| path.file_name()).any(|file| match self { + Interest::Logs => file.to_str().is_some_and(|f| f.ends_with(EVENTS_SUFFIX)), + Interest::Files(files) => files.contains(file), + }) + } +} + // Read/open/close-read notifications must never feed back into another scan. fn wake_on_change(tx: &SyncSender<()>, result: notify::Result) { if let Ok(event) = result @@ -162,6 +208,7 @@ fn wake_on_change(tx: &SyncSender<()>, result: notify::Result) { // polling continues to discover logs in the replacement directory. fn watch_event( dir: &Path, + interest: &Interest, wake: &SyncSender<()>, retire: &SyncSender<()>, result: notify::Result, @@ -177,7 +224,7 @@ fn watch_event( }; if invalidated { let _ = retire.try_send(()); - } else { + } else if result.as_ref().is_ok_and(|event| interest.covers(event)) { wake_on_change(wake, result); } } @@ -199,11 +246,25 @@ fn registry_entry_removed(name: &str) -> bool { !registry::is_creation_lock_held(name) && !metadata_path(name).exists() } +// A daemon records its pid when it starts. One that did and is now gone +// without recording an exit can append nothing more. A record no daemon has +// claimed may be a launcher yet to start, and a held creation lock is a +// respawn in progress. +fn daemon_vanished(name: &str) -> bool { + registry::get_session_by_name(name).is_some_and(|session| { + session.status == registry::SessionStatus::Vanished + && (session.metadata.as_ref().is_some_and(|record| record.daemon_pid.is_some()) + || pid_path(name).exists()) + }) && !registry::is_creation_lock_held(name) +} + fn run( options: FollowerOptions, mut on_event: impl FnMut(Event), stop: Arc, ready: Sender<()>, + wake_tx: SyncSender<()>, + wake_rx: Receiver<()>, ) { let dir = session_dir(); let mut tracked: BTreeMap = BTreeMap::new(); @@ -239,18 +300,16 @@ fn run( // starting an FSEvents stream took 3.5 s on a busy macOS host, and the // poll below has to keep delivering meanwhile. That thread holds the // watcher until shutdown, a backend error, or registry removal. - // A bounded signal coalesces bursts without an unbounded drain that can - // prevent shutdown while another process keeps changing the directory. - let (wake_tx, wake_rx) = sync_channel(1); let (release_tx, release_rx) = sync_channel(1); let watch_dir = dir.clone(); let retire_tx = release_tx.clone(); + let interest = Interest::new(options.names.as_deref()); let _ = std::thread::Builder::new() .name("events-follow-watch".to_string()) .spawn(move || { let callback_dir = watch_dir.clone(); let Ok(mut watcher) = notify::recommended_watcher(move |result| { - watch_event(&callback_dir, &wake_tx, &retire_tx, result); + watch_event(&callback_dir, &interest, &wake_tx, &retire_tx, result); }) else { return; }; @@ -287,7 +346,15 @@ fn run( // metadata. It may have done both after our first log read. read_new_lines(t, &mut on_event); } - !exited && !removed && !retained_exit + if exited || removed || retained_exit { + return false; + } + let vanished = daemon_vanished(name); + if vanished { + // Its last records may have landed after our first read. + read_new_lines(t, &mut on_event); + } + !vanished }); if !follow_all && tracked.is_empty() { break; @@ -444,7 +511,7 @@ mod tests { EventKind::Access(AccessKind::Read), EventKind::Access(AccessKind::Close(AccessMode::Read)), ] { - watch_event(dir, &wake_tx, &retire_tx, Ok(notify::Event::new(kind))); + watch_event(dir, &Interest::Logs, &wake_tx, &retire_tx, Ok(notify::Event::new(kind))); } // An empty queue after every synthetic scan, rather than only // after a burst, catches a self-sustaining read/scan cycle. @@ -471,14 +538,14 @@ mod tests { let (retire_tx, retire_rx) = sync_channel(1); for _ in 0..100 { let result = event.clone().ok_or_else(|| notify::Error::generic("backend failed")); - watch_event(dir, &wake_tx, &retire_tx, result); + watch_event(dir, &Interest::Logs, &wake_tx, &retire_tx, result); } assert_eq!(retire_rx.try_iter().count(), 1); assert!(matches!(wake_rx.try_recv(), Err(std::sync::mpsc::TryRecvError::Empty))); // Already-retired holders must not block their callback either. drop(retire_rx); let result = event.ok_or_else(|| notify::Error::generic("backend failed")); - watch_event(dir, &wake_tx, &retire_tx, result); + watch_event(dir, &Interest::Logs, &wake_tx, &retire_tx, result); } } @@ -489,6 +556,7 @@ mod tests { let (retire_tx, retire_rx) = sync_channel(1); watch_event( Path::new("/registry"), + &Interest::Logs, &wake_tx, &retire_tx, Ok(notify::Event::new(EventKind::Remove(RemoveKind::File)) @@ -498,6 +566,35 @@ mod tests { assert!(matches!(retire_rx.try_recv(), Err(std::sync::mpsc::TryRecvError::Empty))); } + #[test] + fn only_changes_to_followed_files_wake_the_follower() { + use notify::event::{CreateKind, DataChange, ModifyKind, RemoveKind, RenameMode}; + let dir = Path::new("/registry"); + let change = |kind, file: &str| notify::Event::new(kind).add_path(dir.join(file)); + let write = EventKind::Modify(ModifyKind::Data(DataChange::Any)); + let rename = EventKind::Modify(ModifyKind::Name(RenameMode::To)); + let named = Interest::new(Some(&["mine".to_string()])); + for (interest, event, wakes) in [ + (&named, change(write, "other.events.jsonl"), false), + (&named, change(EventKind::Create(CreateKind::File), "other.json"), false), + (&named, change(write, "mine.events.jsonl.tmp.7.0123456789abcdef"), false), + (&named, change(write, "mine.pid"), false), + (&named, change(rename, "mine.events.jsonl"), true), + (&named, change(rename, "mine.json"), true), + (&named, change(EventKind::Remove(RemoveKind::File), "mine.json"), true), + (&named, notify::Event::new(write), true), + (&Interest::Logs, change(rename, "other.events.jsonl"), true), + (&Interest::Logs, change(write, "other.json"), false), + (&Interest::Logs, change(write, "other.events.jsonl.tmp.7.0123456789abcdef"), false), + ] { + let (wake_tx, wake_rx) = sync_channel(1); + let (retire_tx, _retire_rx) = sync_channel(1); + let description = format!("{:?}", event.paths); + watch_event(dir, interest, &wake_tx, &retire_tx, Ok(event)); + assert_eq!(wake_rx.try_recv().is_ok(), wakes, "{description}"); + } + } + #[test] fn disconnected_watcher_sleeps_once_per_poll_but_notifications_do_not() { let interval = Duration::from_millis(250); diff --git a/crates/pty-core/tests/events_follow.rs b/crates/pty-core/tests/events_follow.rs index 5812d397..2a448f4c 100644 --- a/crates/pty-core/tests/events_follow.rs +++ b/crates/pty-core/tests/events_follow.rs @@ -88,6 +88,25 @@ fn an_event_appended_right_after_start_is_delivered() { } } +/// A stop interrupts the poll wait rather than waiting out the interval, so +/// a wait that matched exits at once. +#[test] +fn stop_does_not_wait_for_the_next_poll() { + let _ = root(); + let name = unique_name("stop"); + events::clear_events(&name).unwrap(); + let (mut follower, _rx) = EventFollower::channel(FollowerOptions { + poll_interval: Duration::from_secs(30), + ..FollowerOptions::names(vec![name.clone()]) + }); + // Let the thread reach its poll wait, where only a wake-up interrupts it. + // A stop before that is seen at the top of the loop without one. + std::thread::sleep(Duration::from_millis(200)); + let started = Instant::now(); + follower.stop(); + assert!(started.elapsed() < Duration::from_secs(5), "{:?}", started.elapsed()); +} + #[test] fn follower_sees_retained_new_records_when_a_batch_shrinks_and_regrows() { let _ = root(); diff --git a/crates/pty/src/cli/events.rs b/crates/pty/src/cli/events.rs index 6f639558..dfda593e 100644 --- a/crates/pty/src/cli/events.rs +++ b/crates/pty/src/cli/events.rs @@ -117,7 +117,15 @@ pub fn run(args: &[String]) -> CliResult { timeout = js_parse_float(cur.take_value().unwrap_or_default()); } _ if reference.is_none() => reference = cur.next(), - _ => break, + // Ignoring it would also drop every option after it, such as a + // deadline (`--timeout=60`) or the wait itself (`--wait=`). + // An unknown dash token taken as the reference is the stray one + // when a name follows it (`--timeout=60 NAME`). + Some(unexpected) => { + let stray = reference.filter(|r| r.starts_with('-')).unwrap_or(unexpected); + return Err(format!("Unexpected argument: {stray}").into()); + } + None => break, } } @@ -227,7 +235,15 @@ fn cmd_events( if print_recorded_exit(name, wait_type, json) { return Ok(0); } - eprintln!("Session \"{name}\" ended before a \"{wait_type}\" event was observed."); + let vanished = registry::get_session_by_name(name) + .is_some_and(|session| session.status == registry::SessionStatus::Vanished); + if vanished && wait_type == pty_core::events::event_type::SESSION_EXIT { + eprintln!("Session \"{name}\" vanished without a recorded exit."); + } else if vanished { + eprintln!("Session \"{name}\" vanished before a \"{wait_type}\" event was observed."); + } else { + eprintln!("Session \"{name}\" ended before a \"{wait_type}\" event was observed."); + } return Ok(1); } } diff --git a/crates/pty/tests/cli_events.rs b/crates/pty/tests/cli_events.rs index 2b36be0b..61bd035c 100644 --- a/crates/pty/tests/cli_events.rs +++ b/crates/pty/tests/cli_events.rs @@ -334,3 +334,59 @@ fn follower_exits_after_a_real_session_ends() { let out = finish_within(child, Duration::from_secs(3)); assert_eq!(out.status.code(), Some(0), "{out:?}"); } + +#[test] +fn an_unexpected_argument_is_refused_rather_than_dropping_the_options_after_it() { + let rig = Rig::new(); + rig.write_meta("strict", json!({})); + for (args, unexpected) in [ + (vec!["events", "strict", "--wait", "user.never", "--timeout=1"], "--timeout=1"), + (vec!["events", "strict", "--wait", "user.never", "-t=1"], "-t=1"), + (vec!["events", "strict", "--wait=user.never", "-t", "1"], "--wait=user.never"), + (vec!["events", "strict", "--wait", "user.never", "--bogus", "-t", "1"], "--bogus"), + (vec!["events", "--wait", "user.never", "-t", "1", "strict", "other"], "other"), + (vec!["events", "strict", "--json", "--wait"], "--wait"), + (vec!["events", "--timeout=1", "strict"], "--timeout=1"), + ] { + let child = rig.cmd(&args).stdout(Stdio::piped()).stderr(Stdio::piped()).spawn().unwrap(); + let out = finish_within(child, Duration::from_secs(2)); + assert_eq!(out.status.code(), Some(1), "{args:?}: {out:?}"); + assert_eq!( + String::from_utf8_lossy(&out.stderr), + format!("Unexpected argument: {unexpected}\n"), + "{args:?}" + ); + } +} + +/// A daemon that recorded itself and died without recording an exit can +/// append nothing more, so waits and named follows on it end, whether they +/// started before it died or after. A record no daemon claimed keeps waiting +/// (`wait_prints_the_first_matching_event_or_times_out`). +#[test] +fn waits_and_follows_end_when_their_daemon_vanishes() { + let rig = Rig::new(); + rig.spawn_cat("doomed", &[]); + let pid: i32 = std::fs::read_to_string(rig.path("doomed.pid")) + .unwrap().trim().parse().unwrap(); + let spawn = |args: &[&str]| { + rig.cmd(args).stdout(Stdio::piped()).stderr(Stdio::piped()).spawn().unwrap() + }; + let user_wait = ["events", "doomed", "--wait", "user.never", "-t", "3600"]; + let exit_wait = ["events", "doomed", "--wait", "session_exit", "-t", "3600"]; + let follow = ["events", "doomed", "--json"]; + let before = [spawn(&user_wait), spawn(&exit_wait), spawn(&follow)]; + pty_core::kill::process(pid, libc::SIGKILL).unwrap(); + let after = [spawn(&user_wait), spawn(&exit_wait), spawn(&follow)]; + for (i, child) in before.into_iter().chain(after).enumerate() { + let out = finish_within(child, Duration::from_secs(3)); + let stderr = String::from_utf8_lossy(&out.stderr); + let (code, message) = match i % 3 { + 0 => (1, "Session \"doomed\" vanished before a \"user.never\" event was observed.\n"), + 1 => (1, "Session \"doomed\" vanished without a recorded exit.\n"), + _ => (0, ""), + }; + assert_eq!(out.status.code(), Some(code), "{i}: {out:?}"); + assert_eq!(stderr, message, "{i}"); + } +} diff --git a/crates/pty/tests/fixtures/help/events.txt b/crates/pty/tests/fixtures/help/events.txt index e9f0cee8..e109f558 100644 --- a/crates/pty/tests/fixtures/help/events.txt +++ b/crates/pty/tests/fixtures/help/events.txt @@ -10,8 +10,9 @@ Flags: --wait Block until an event of appears -t, --timeout Timeout (seconds) for --wait or follow; exit 1 on timeout -Options may appear before or after . A named follow exits when the session -exits or its registry entry is removed outside a locked respawn; --all continues +Options may appear before or after ; any other argument is an error. A named +follow exits when the session exits, its daemon vanishes without recording an +exit, or its registry entry is removed outside a locked respawn; --all continues watching new sessions. Terminal metadata is followed by a final event-log drain. --wait exits 1 if the session ends before a matching event, or on timeout. diff --git a/docs/decisions/0021-events-refuses-an-argument-it-does-not-know.md b/docs/decisions/0021-events-refuses-an-argument-it-does-not-know.md new file mode 100644 index 00000000..8327b878 --- /dev/null +++ b/docs/decisions/0021-events-refuses-an-argument-it-does-not-know.md @@ -0,0 +1,66 @@ +# 0021 — `pty events` refuses an argument it does not know + +**Status:** accepted + +**Node behavior.** `pty events` (`src/cli.ts`, the `events` case) reads +options only before the session name, and stops at the first token it does +not know. That token becomes the name, and every argument after the name is +ignored. So `pty events NAME --wait T -t 60` follows `NAME` with no wait and +no deadline, and runs until it is killed. + +**Rust before.** Since ad48f88, options may also follow the name, but the +first token the parser did not know still ended parsing, and everything after +it was ignored. `--timeout=60`, `-t=60` and `--wait=T` are not spelled the way +the parser reads them, so each one dropped the deadline, and `--wait=T` the +wait as well. The command then ran forever with no error (#218). + +Measured with no terminal, against the pinned Node reference on Node +22.23.2, main `8dd3fd42`, and this change. `q` is a running session, and each +run was killed at 4 s: + +| command | Node | Rust before | Rust now | +| --- | --- | --- | --- | +| `pty events --wait user.x -t 2 q` | exit 1 at 2 s, timed out | exit 1 at 2 s, timed out | exit 1 at 2 s, timed out | +| `pty events q --wait user.x -t 2` | ran on | exit 1 at 2 s, timed out | exit 1 at 2 s, timed out | +| `pty events q --wait user.x --timeout=2` | ran on | ran on | exit 1 at once: `Unexpected argument: --timeout=2` | +| `pty events q --wait user.x -t=2` | ran on | ran on | exit 1 at once: `Unexpected argument: -t=2` | +| `pty events q --wait=user.x -t 2` | ran on | ran on | exit 1 at once: `Unexpected argument: --wait=user.x` | +| `pty events q --wait user.x --bogus -t 2` | ran on | ran on | exit 1 at once: `Unexpected argument: --bogus` | +| `pty events --wait user.x -t 2 q other` | exit 1 at 2 s, timed out | exit 1 at 2 s, timed out | exit 1 at once: `Unexpected argument: other` | +| `pty events --timeout=2 q` | exit 1: `Session "--timeout=2" not found.` | the same | exit 1 at once: `Unexpected argument: --timeout=2` | + +**Rust behavior.** After the name, an argument that is not one of +`pty events`' options, or a second name, is an error: `Unexpected argument: +`, exit 1, before anything is followed. That is `pty send`'s message +for the same mistake. When an unknown dash token comes before the name, the +error names that token. A lone unknown dash token is still taken as the name, +as in Node, so `pty events --bogus` still says `Session "--bogus" not found.` + +**Why.** A wait whose deadline was dropped never ends, and #218 reported waits +that ran well past `-t 7200`. A caller cannot tell a dropped option from a +slow event, so the mistake has to surface at once. An error costs a script one fix. A silently ignored option +costs a process that never exits. + +**Client effect.** +- A script that passed a stray argument to `pty events` now exits 1 where it + used to run with the argument ignored, or with every option after it + ignored. +- Spell the options `-t ` or `--timeout `, and `--wait `, as + separate arguments. `--timeout=60`, `-t=60` and `--wait=` are errors. +- At most one session name. + +**Test.** `crates/pty/tests/cli_events.rs`, +`an_unexpected_argument_is_refused_rather_than_dropping_the_options_after_it`, +checks seven spellings, each exiting 1 at once with the exact message. No +conformance test passes `pty events` an argument it does not know, so the +divergence ledger needs no entry. + +**Related.** The same change (#219) ends a wait or a named follow when the +session's daemon has recorded its pid and then dies without recording an +exit. Before, it waited forever, as Node's does. That extends ad48f88 and #197, +which end a wait when the session's exit is recorded or its entry is removed. + +**Migration / negotiation.** None on the wire. Release note: `pty events` now +rejects an argument it does not recognise (exit 1), instead of ignoring it and +every option after it. Pass `-t `, not `-t=60` or `--timeout=60`, and +`--wait `. diff --git a/docs/parity.md b/docs/parity.md index f823fb74..f01a2934 100644 --- a/docs/parity.md +++ b/docs/parity.md @@ -384,6 +384,7 @@ Decided on 2026-08-29. Each row records the decision. | `attach`'s dead-session prompt restarting with no terminal on any line but `n` | S | Not reproduced, on purpose. Off a terminal only `y` or `yes` restarts, and EOF never does. With no answer, attach exits 1 and names `-r`, where Node exits 0 at EOF and restarts on any other line. Accepted, decision 0020. | | `restart`'s running-session prompt stopping and restarting with no terminal on any line but `n` | S | Not reproduced, on purpose. The same rule as `attach`'s prompt: with no answer, `restart` exits 1 and leaves the session running, and names `-y`. Node exits 0 at EOF and restarts on any other line. Accepted, decision 0020. | | `no` at a restart prompt counting as yes | S | Not reproduced, on purpose. A lone `n` or `no`, in any case, declines `attach`'s and `restart`'s prompts and exits 0. Node declines only on a lone `n`. Accepted, decision 0020. | +| `pty events` ignoring an argument it does not know, and every option after it | S | Not reproduced, on purpose. After the session name, an unknown argument or a second name exits 1 with `Unexpected argument: `, so `--timeout=60` or `--wait=` can no longer drop the deadline or the wait. Node reads no options after the name at all. Accepted, decision 0021. | ## 12c. What differs because the kernel differs