diff --git a/crates/thalyx-rust/src/analyzer.rs b/crates/thalyx-rust/src/analyzer.rs index b0f7a81..3e53737 100644 --- a/crates/thalyx-rust/src/analyzer.rs +++ b/crates/thalyx-rust/src/analyzer.rs @@ -38,10 +38,11 @@ //! exist: a failure to read is not a failure to exist. use serde_json::{Value, json}; -use std::io::{BufRead, BufReader, Write}; +use std::io::{BufRead, BufReader, Read, Write}; use std::path::{Path, PathBuf}; use std::process::{Child, ChildStdin, Command, Stdio}; use std::sync::mpsc::{Receiver, RecvTimeoutError, channel}; +use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant}; use crate::{Result, RustError}; @@ -148,10 +149,15 @@ impl Spawn for OnTheHost { .current_dir(asked.root) .stdin(Stdio::piped()) .stdout(Stdio::piped()) - // Its log is noise on the way to an answer, and a pipe nobody + // It was the null device, for the reason that a pipe nobody // drains is a server that blocks on a full buffer halfway through - // indexing — which would look exactly like a server that hung. - .stderr(Stdio::null()) + // indexing — which looks exactly like a server that hung. Somebody + // drains it now: `Analyzer::start` reads it continuously and keeps + // only the last of it, so the log costs nothing while the server + // lives and is there the moment it dies. The confined path has + // always had this pipe; having it here too means a death is + // diagnosed the same way whichever spawner started the process. + .stderr(Stdio::piped()) .spawn() .map_err(|error| { RustError::NoAnalyzer(format!("{}: {error}", asked.program.display())) @@ -165,6 +171,153 @@ impl Spawn for OnTheHost { } } +// ── what the server said on its way out ────────────────────────────────────── + +/// How much of the server's `stderr` is kept for the moment it dies. +/// +/// A ceiling and not a buffer that grows: rust-analyzer logs while it indexes, +/// and a server held for the length of a session can write more than anybody +/// will ever read. Four kilobytes is a panic with its message, a linker error +/// or a runtime's complaint — which is what is wanted at the one moment this +/// gets read. +const STDERR_KEPT: usize = 4096; + +/// How long to wait for the process's status once its channel has closed. +/// +/// The pipe closing and the process being reaped are two events, in that order, +/// and asking for the status at the instant of the first would answer "still +/// running" for a process that has already died. Bounded, because a diagnosis +/// that blocks is worse than one that is vague. +const EPITAPH_GRACE: Duration = Duration::from_millis(500); + +/// The tail of what the server wrote to `stderr`, and how much of it there was. +/// +/// The **last** bytes and not the first. A process that dies says why on the +/// way out, and one that logged its way through an indexing pass first would +/// otherwise fill any buffer with progress before reaching the sentence that +/// matters. +#[derive(Default)] +struct LastWords { + tail: Vec, + total: usize, + /// Whether the pipe reached its end. Read before the tail is quoted, so a + /// diagnosis is not written while the dying process's last line is still in + /// flight — rule 5, where the instrument is this reader. + closed: bool, +} + +impl LastWords { + fn push(&mut self, bytes: &[u8]) { + self.total += bytes.len(); + self.tail.extend_from_slice(bytes); + if self.tail.len() > STDERR_KEPT { + self.tail.drain(..self.tail.len() - STDERR_KEPT); + } + } + + /// Rendered into a sentence, saying plainly when something was dropped. + /// + /// Control characters go and newlines and tabs stay: rust-analyzer colours + /// its log, and an escape sequence pasted into a diagnosis is a diagnosis + /// that repaints the terminal somebody reads it on. + fn spoken(&self) -> String { + if self.total == 0 { + return "it wrote nothing to stderr".to_string(); + } + let text: String = String::from_utf8_lossy(&self.tail) + .chars() + .map(|c| { + if c == '\n' || c == '\t' || !c.is_control() { + c + } else { + ' ' + } + }) + .collect(); + let text = text.trim(); + if self.total > self.tail.len() { + format!( + "its stderr, the last {} of {} bytes: {text}", + self.tail.len(), + self.total + ) + } else { + format!("its stderr, {} bytes: {text}", self.total) + } + } +} + +/// Drain a dying server's `stderr` into a bounded tail, forever. +/// +/// **Drained and not merely piped.** `launch::spawn` has always given a +/// confined program a `stderr` pipe, and nothing on this path ever read it: a +/// pipe whose reader never empties it blocks the writer on a full buffer, which +/// is a server that stops mid-indexing and looks exactly like one that hung. +/// Reading it continuously and keeping only the end is what makes the pipe safe +/// to have at all. +fn keep_last_words(stderr: Option) -> Arc> { + let kept = Arc::new(Mutex::new(LastWords::default())); + let Some(mut stderr) = stderr else { + // No pipe is not "the pipe has not closed yet". Saying so here is what + // stops `epitaph` from spending its grace waiting for an end that + // cannot come. + held(&kept).closed = true; + return kept; + }; + let into = Arc::clone(&kept); + std::thread::spawn(move || { + let mut chunk = [0u8; 1024]; + loop { + match stderr.read(&mut chunk) { + Ok(0) | Err(_) => break, + Ok(read) => held(&into).push(&chunk[..read]), + } + } + held(&into).closed = true; + }); + kept +} + +/// The tail, whoever poisoned the lock. +/// +/// A panicking drain thread must not turn a diagnosis into a second panic: the +/// whole reason this exists is to be readable at the worst moment. +fn held(kept: &Arc>) -> std::sync::MutexGuard<'_, LastWords> { + kept.lock().unwrap_or_else(|poisoned| poisoned.into_inner()) +} + +/// The name of a signal, for a number nobody should have to look up. +/// +/// Spelled here rather than taken from a crate: this crate has no `libc` +/// dependency, and taking one on to name thirty constants would be a build-time +/// dependency for a string. The numbers are Linux's on x86-64 and aarch64, +/// which is what Thalyx runs on. `SIGSYS` is the one this was written for — a +/// process killed by the seccomp filter dies of it, and 31 on its own tells the +/// person reading nothing. +fn signal_name(number: i32) -> &'static str { + match number { + 1 => "SIGHUP", + 2 => "SIGINT", + 3 => "SIGQUIT", + 4 => "SIGILL", + 5 => "SIGTRAP", + 6 => "SIGABRT", + 7 => "SIGBUS", + 8 => "SIGFPE", + 9 => "SIGKILL", + 10 => "SIGUSR1", + 11 => "SIGSEGV", + 12 => "SIGUSR2", + 13 => "SIGPIPE", + 14 => "SIGALRM", + 15 => "SIGTERM", + 24 => "SIGXCPU", + 25 => "SIGXFSZ", + 31 => "SIGSYS", + _ => "unnamed here", + } +} + /// How long to wait for the server to finish its first indexing pass. /// /// Measured rather than guessed: this workspace's twenty-eight crates take @@ -240,6 +393,9 @@ pub struct Analyzer { /// Whether Thalyx's confinement stands behind it. confined: bool, stdin: ChildStdin, + /// The tail of what it wrote to `stderr`, drained continuously and read + /// only when it dies. See [`Analyzer::epitaph`]. + noise: Arc>, incoming: Receiver, next_id: i64, root: PathBuf, @@ -289,6 +445,9 @@ impl Analyzer { let stdout = child.stdout.take().ok_or_else(|| { RustError::NoAnalyzer("rust-analyzer was started without a stdout".to_string()) })?; + // Started before the first byte is sent, because the death this is for + // happens during `initialize` and what it said is on its way out then. + let noise = keep_last_words(child.stderr.take()); // A reader thread and a channel rather than reading in line: every read // here needs a deadline, and a blocking read on a pipe has none. A @@ -309,6 +468,7 @@ impl Analyzer { how, confined, stdin, + noise, incoming, next_id: 1, root: root.to_path_buf(), @@ -571,6 +731,65 @@ impl Analyzer { } } + /// What became of the server, said at the moment its channel closes. + /// + /// Until 2026-08-30 a server that died during `initialize` produced exactly + /// one sentence — *«the server stopped»* — which is the shape rule 10 is + /// about: it reports that the reading failed and nothing about what + /// happened. A process killed by the seccomp filter, a process that could + /// not find its toolchain and a process that panicked all closed a pipe, + /// and on Fedora on 2026-08-30 they were indistinguishable events. Stage 58 + /// could say `analyzer_starts=1` and then that the server stopped, with + /// `ausearch -m SECCOMP` showing nothing, and no way to tell which of the + /// three it had been. + /// + /// So the two things the kernel already knows get read: how the process + /// ended — a status, or the signal that killed it — and the last of what it + /// wrote on the way out. + /// + /// Bounded on both sides. The wait for the status is [`EPITAPH_GRACE`] and + /// then it says the process was still running, rather than becoming a + /// diagnosis that hangs; the stderr quoted is the last [`STDERR_KEPT`] + /// bytes, and it says so when there was more. + fn epitaph(&mut self) -> String { + let deadline = Instant::now() + EPITAPH_GRACE; + let mut ended: Option> = None; + loop { + if ended.is_none() { + match self.child.try_wait() { + Ok(Some(status)) => ended = Some(Ok(status)), + Ok(None) => {} + // Rule 10: a failure to read is not a failure to exist, and + // "could not be asked" is not "was still running". + Err(error) => ended = Some(Err(error.to_string())), + } + } + if (ended.is_some() && held(&self.noise).closed) || Instant::now() >= deadline { + break; + } + std::thread::sleep(Duration::from_millis(10)); + } + + let how = match ended { + Some(Ok(status)) => { + use std::os::unix::process::ExitStatusExt; + if let Some(signal) = status.signal() { + format!( + "the process was killed by signal {signal} ({})", + signal_name(signal) + ) + } else if let Some(code) = status.code() { + format!("the process exited with status {code}") + } else { + format!("the process ended as {status}") + } + } + Some(Err(why)) => format!("how the process ended could not be read: {why}"), + None => format!("the process was still running {EPITAPH_GRACE:?} later"), + }; + format!("{how}; {}", held(&self.noise).spoken()) + } + fn request_once(&mut self, method: &str, params: Value, ceiling: Duration) -> Result { let id = self.next_id; self.next_id += 1; @@ -584,7 +803,13 @@ impl Analyzer { return Err(RustError::Silent(format!("`{method}` after {ceiling:?}"))); } Err(RecvTimeoutError::Disconnected) => { - return Err(RustError::Silent(format!("`{method}`: the server stopped"))); + // The one place the death is visible, and until this said + // more than "it stopped" there was nothing to diagnose it + // with. See [`Analyzer::epitaph`]. + let epitaph = self.epitaph(); + return Err(RustError::Silent(format!( + "`{method}`: the server stopped — {epitaph}" + ))); } }; if message.get("id").and_then(Value::as_i64) != Some(id) { @@ -612,11 +837,25 @@ impl Analyzer { let body = serde_json::to_vec(&message).map_err(|error| { RustError::Silent(format!("a request could not be written: {error}")) })?; - self.stdin + let written = self + .stdin .write_all(format!("Content-Length: {}\r\n\r\n", body.len()).as_bytes()) .and_then(|()| self.stdin.write_all(&body)) - .and_then(|()| self.stdin.flush()) - .map_err(|error| RustError::Silent(format!("the server stopped listening: {error}"))) + .and_then(|()| self.stdin.flush()); + // The same death seen from the writing side, and it is a real race + // rather than a second case: a server that dies before the request is + // written fails here with `EPIPE`, and one that dies just after fails + // as a disconnected channel above. Which of the two happens is timing, + // so both carry the epitaph or the diagnosis is a coin toss. + match written { + Ok(()) => Ok(()), + Err(error) => { + let epitaph = self.epitaph(); + Err(RustError::Silent(format!( + "the server stopped listening: {error} — {epitaph}" + ))) + } + } } } diff --git a/crates/thalyx-rust/tests/a_server_that_dies_says_how_it_died.rs b/crates/thalyx-rust/tests/a_server_that_dies_says_how_it_died.rs new file mode 100644 index 0000000..7db7ffc --- /dev/null +++ b/crates/thalyx-rust/tests/a_server_that_dies_says_how_it_died.rs @@ -0,0 +1,143 @@ +//! What the diagnosis says when the semantic provider dies before it answers. +//! +//! Written on 2026-08-30, from physical evidence on Fedora that could not be +//! read. Stage 58 reported `analyzer_starts=1` and then +//! `rust-analyzer did not answer: initialize: the server stopped`; `ausearch -m +//! SECCOMP` over the exact seconds of the run showed no SECCOMP, no AVC and no +//! other kill. So the machine held one sentence about the death, and that +//! sentence — *«the server stopped»* — is rule 10's failure shape: it says the +//! reading failed and nothing about what happened. A process killed by the +//! filter, a process that could not find its toolchain, and a process that +//! panicked all close a pipe. +//! +//! These tests do not reproduce that death — nothing here can, this container +//! cannot confine anything. They establish the **instrument**: that when a +//! server dies before or during `initialize`, the refusal carries how the +//! process ended and what it wrote on the way out, bounded. +//! +//! The stand-in is a shell that behaves the way the property under test needs — +//! rule 8. It is asked to die by `SIGSYS`, which is not an approximation of a +//! seccomp kill: a process killed by the filter dies of exactly that signal. + +use std::path::{Path, PathBuf}; +use std::process::{Command, Stdio}; + +use thalyx_rust::analyzer::{Analyzer, Launching, Spawn, Started}; + +/// A server that is not one: a shell told what to do instead of speaking LSP. +/// +/// It reads one line first, so that Thalyx's `initialize` is written to a +/// process that is still alive. Without that the death is a race between +/// `EPIPE` on the write and the channel closing on the read, and a test that +/// raced would prove the diagnosis on whichever side won that day. +struct DiesLike(&'static str); + +impl Spawn for DiesLike { + fn start(&self, _asked: Launching<'_>) -> thalyx_rust::Result { + let child = Command::new("/bin/sh") + .arg("-c") + .arg(format!("read _ignored; {}", self.0)) + .stdin(Stdio::piped()) + .stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .spawn() + .expect("a shell to stand in for a server"); + Ok(Started { + child, + release: None, + how: "a stand-in".to_string(), + confined: false, + }) + } +} + +/// Start one against a directory that need not be a workspace: nothing here +/// gets as far as reading it. +fn refusal_from(dies_like: &'static str) -> String { + let root = PathBuf::from("."); + let error = Analyzer::start( + &root, + Path::new("/nonexistent-the-spawner-decides"), + None, + &[], + &[], + &DiesLike(dies_like), + ) + .err() + .expect("a server that dies cannot have started"); + error.to_string() +} + +#[test] +fn a_server_killed_by_a_signal_names_the_signal() { + let said = refusal_from("kill -SYS $$"); + assert!( + said.contains("killed by signal 31") && said.contains("SIGSYS"), + "a process killed by the signal the seccomp filter uses must be \ + reported as that, and this said: {said}" + ); +} + +#[test] +fn a_server_that_exits_names_its_status() { + let said = refusal_from("exit 101"); + assert!( + said.contains("exited with status 101"), + "a server that exited must be told apart from one that was killed, \ + and this said: {said}" + ); + assert!( + !said.contains("killed by signal"), + "an ordinary exit reported as a signal is the confusion this exists \ + to end: {said}" + ); +} + +#[test] +fn what_the_server_wrote_before_dying_is_in_the_refusal() { + // The sentence that matters is always the last one, which is why the tail + // is kept rather than the head: a real server logs its way through an + // indexing pass before it says why it is going. + let said = refusal_from( + "echo 'indexing, nothing to see' >&2; \ + echo 'thread panicked: could not find the toolchain' >&2; exit 1", + ); + assert!( + said.contains("could not find the toolchain"), + "the reason a server gave for dying must survive to the refusal, and \ + this said: {said}" + ); +} + +#[test] +fn a_server_that_said_nothing_is_reported_as_having_said_nothing() { + // Rule 10 again, one level down: "it wrote nothing" and "nothing was read" + // are different facts, and a diagnosis that omitted the sentence entirely + // would leave the reader unable to tell which happened. + let said = refusal_from("exit 3"); + assert!( + said.contains("wrote nothing to stderr"), + "silence is a finding and must be stated, and this said: {said}" + ); +} + +#[test] +fn a_server_that_writes_without_stopping_does_not_fill_this_process() { + // The half of this that is not diagnosis: the confined path has always had + // a stderr pipe and nothing ever drained it, so a chatty server would block + // on a full buffer — a hang that looks like an unresponsive server. Draining + // it is what makes keeping it safe, and the tail is what keeps the draining + // bounded. A megabyte, which is far past any buffer this could accumulate in. + let said = refusal_from("yes 'a log line nobody will ever read' | head -c 1000000 >&2; exit 7"); + assert!( + said.contains("exited with status 7"), + "a server that wrote a megabyte and then exited must still be waited \ + on and reported, and this said: {said}" + ); + assert!( + said.contains("the last 4096 of 1000000 bytes"), + "the quoted tail must be bounded and must say how much was dropped, \ + and this said: {}", + &said[..said.len().min(400)] + ); +}