diff --git a/crates/spt/tests/common/mod.rs b/crates/spt/tests/common/mod.rs index a5da2f8f..312d1ce5 100644 --- a/crates/spt/tests/common/mod.rs +++ b/crates/spt/tests/common/mod.rs @@ -76,6 +76,99 @@ pub fn daemon_stderr_panel(pre_redirect: &Path) -> String { ) } +/// What [`preserve_stderr_evidence`] saved, and the part of it a CI log can show. +pub struct PreservedEvidence { + /// Where the whole sinks were copied. Named in the panic so a local run can + /// open them; on CI the directory usually dies with the runner, which is why + /// `tail` exists beside it. + pub dir: std::path::PathBuf, + /// A BOUNDED tail of the daemon/brain stderr sink, for pasting straight into + /// a panic message. Bounded because a panic that dumps an unbounded log is a + /// panic nobody reads. + pub tail: String, + /// What was copied, or why it was not. Never silent: a preservation step + /// that fails quietly is worse than none, because the failure text will + /// promise evidence that is not there. + pub note: String, +} + +/// Copy the daemon/brain stderr sinks OUT of a run's temp home before the +/// assertions can abort the test. +/// +/// THE MECHANISM THIS EXISTS FOR: the run's `SPT_HOME` is a `TempDir`. A failing +/// assertion unwinds, the `TempDir` drops, and the drop deletes the directory — +/// so the failure that most needs the brain's own stderr is precisely the one +/// that destroys it. Copying is not tidiness; it is the difference between a +/// leak red you can diagnose and one you can only re-run. Do not "simplify" this +/// away: the panic message that cites `dir` is written on the assumption the +/// copy already happened. +/// +/// Destination: `/test-artifacts///`, overridable with +/// `SPT_TEST_ARTIFACTS`. Under `target/` on purpose — it is the tree `cargo +/// clean` already owns, it is per-checkout, and it is neither a scratchpad (not +/// preservation) nor `.spt/preserved` (that is for gated evidence a human filed, +/// not for every local run). +pub fn preserve_stderr_evidence(home: &Path, rig: &str) -> PreservedEvidence { + const TAIL_LINES: usize = 200; + + let stamp = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map(|d| d.as_millis().to_string()) + .unwrap_or_else(|_| "unknown-epoch".to_string()); + + // `target/` from THIS test binary rather than from a guessed path: the exe + // is `//deps/`, so two hops up is the profile dir and + // three is the target root, whatever `CARGO_TARGET_DIR` was spelled as. + let root = std::env::var_os("SPT_TEST_ARTIFACTS") + .map(std::path::PathBuf::from) + .or_else(|| { + std::env::current_exe().ok().and_then(|exe| { + exe.ancestors() + .nth(3) + .map(|target| target.join("test-artifacts")) + }) + }) + .unwrap_or_else(std::env::temp_dir); + let dir = root.join(rig).join(&stamp); + + let sink = spt_daemon::stderrlog::sink_path(home); + let pre_redirect = home.join("daemon.stderr.log"); + + let mut notes = Vec::new(); + if let Err(error) = std::fs::create_dir_all(&dir) { + notes.push(format!("create_dir_all({}) FAILED: {error}", dir.display())); + } + for src in [&sink, &pre_redirect] { + let Some(name) = src.file_name() else { continue }; + match std::fs::copy(src, dir.join(name)) { + Ok(bytes) => notes.push(format!("{} -> {bytes} bytes", src.display())), + // An ABSENT sink is a finding, not a non-event: it means the daemon + // never wrote one, which is itself the answer to some leak reds. + Err(error) => notes.push(format!("{} NOT copied: {error}", src.display())), + } + } + + let tail = match std::fs::read_to_string(&sink) { + Ok(text) => { + let lines: Vec<&str> = text.lines().collect(); + let skipped = lines.len().saturating_sub(TAIL_LINES); + let body = lines[skipped..].join("\n"); + if skipped == 0 { + body + } else { + format!("… {skipped} earlier line(s) elided …\n{body}") + } + } + Err(error) => format!("daemon/brain stderr sink UNREADABLE at {}: {error}", sink.display()), + }; + + PreservedEvidence { + dir, + tail, + note: notes.join("; "), + } +} + fn terminate_captured_tree(child: &mut Child) { #[cfg(windows)] { diff --git a/crates/spt/tests/common/reap.rs b/crates/spt/tests/common/reap.rs index 7e84d63e..819a7df6 100644 --- a/crates/spt/tests/common/reap.rs +++ b/crates/spt/tests/common/reap.rs @@ -258,10 +258,60 @@ fn under_root(exe: &Path, root: &Path) -> bool { /// reason a process that never existed is. Counting it separately is what keeps /// "zero survivors" from meaning "zero visible survivors" — a zero that cannot /// see (the run-scoped-cleanup denial IR-8 documents, on this same image). +/// One process that outlived the test, stamped with what a reader needs to +/// IDENTIFY it without a second hunt. +/// +/// A bare `(pid, exe)` names a number and an image, and both are the parts that +/// go stale fastest: by the time the panic is read the pid may belong to someone +/// else, and the image is the same `spt` binary every other process in this +/// suite runs. `started_at` pins WHICH process held the number, and `parent` +/// says who was still holding it open — a leaked service whose parent is our own +/// daemon is a teardown-order defect, and one whose parent is gone (or is the +/// OS) is an orphan, which is a different bug with a different fix. Naming the +/// leaked child of a previous run cost a separate investigation; a survivor that +/// carries its own ancestry answers that in the failure text. +#[derive(Clone, PartialEq, Eq)] +pub struct Survivor { + pub pid: u32, + pub exe: PathBuf, + /// Creation time, `None` when the identity oracle could not answer — which + /// is itself worth printing: an unpinned survivor cannot be re-identified. + pub started_at: Option, + /// The parent AS THE TABLE READS IT NOW. `None` means the table had no entry + /// for this pid by the time we stamped it (it exited between selection and + /// stamping), not that it is parentless. + pub parent: Option, + /// The parent's image, when readable. An unreadable parent path is normal + /// for OS-owned parents and is NOT evidence of anything. + pub parent_exe: Option, + /// Which selector found it: `"staged-root"` (image under this run's own + /// staged root — needs no pid) or `"ancestry"` (descends from a pid observed + /// while it was provably ours). Says WHY we claim it, so a disputed survivor + /// can be argued with. + pub via: &'static str, +} + +/// One line per survivor, because these are read in a CI log where a derived +/// multi-line struct dump buries the pid that matters. +impl std::fmt::Debug for Survivor { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(f, "pid={} via={} exe={}", self.pid, self.via, self.exe.display())?; + match self.started_at { + Some(t) => write!(f, " started_at={t}")?, + None => write!(f, " started_at=UNPINNED")?, + } + match (self.parent, &self.parent_exe) { + (Some(ppid), Some(pexe)) => write!(f, " parent={ppid} ({})", pexe.display()), + (Some(ppid), None) => write!(f, " parent={ppid} (image unreadable)"), + (None, _) => write!(f, " parent=UNKNOWN"), + } + } +} + #[derive(Clone, Debug, Default)] pub struct Population { /// Still running, and its image authenticates it as ours. - pub survivors: Vec<(u32, PathBuf)>, + pub survivors: Vec, /// In ancestry scope, still running, image UNREADABLE. No knowledge — never /// scored as "not ours". pub unreadable: Vec, @@ -328,6 +378,27 @@ pub fn population_sweep( let mut counted: std::collections::HashSet = std::collections::HashSet::new(); let me = std::process::id(); + // ONE snapshot of pid -> ppid for the whole sweep. Read once, deliberately: + // stamping each survivor from its own fresh read would let the table move + // between survivors and produce a parent set that never existed at any + // single instant. + let parents: std::collections::HashMap = + spt_store::proc::process_table().into_iter().collect(); + let stamp = |pid: u32, exe: PathBuf, via: &'static str| -> Survivor { + let parent = parents.get(&pid).copied(); + Survivor { + pid, + exe, + started_at: match spt_store::proc::process_identity(pid) { + ProcIdentity::Present(t) => Some(t), + _ => None, + }, + parent, + parent_exe: parent.and_then(spt_store::proc::exe_path), + via, + } + }; + // ── Half 1: image path under the run's own staged root. ── let root = std::fs::canonicalize(staged_root).unwrap_or_else(|_| staged_root.to_path_buf()); for (pid, _) in spt_store::proc::process_table() { @@ -341,7 +412,7 @@ pub fn population_sweep( continue; }; if under_root(&exe, &root) && counted.insert(pid) { - found.survivors.push((pid, exe)); + found.survivors.push(stamp(pid, exe, "staged-root")); } } @@ -365,7 +436,7 @@ pub fn population_sweep( match spt_store::proc::exe_path(pid) { Some(exe) if same_image(&exe, seed_image) => { if counted.insert(pid) { - found.survivors.push((pid, exe)); + found.survivors.push(stamp(pid, exe, "ancestry")); } } // Descends from something that WAS ours and we cannot read what diff --git a/crates/spt/tests/resident_service_e2e.rs b/crates/spt/tests/resident_service_e2e.rs index 415c505a..76114fd5 100644 --- a/crates/spt/tests/resident_service_e2e.rs +++ b/crates/spt/tests/resident_service_e2e.rs @@ -385,14 +385,47 @@ fn a_declared_service_rises_with_the_daemon_and_reaches_the_cli() { ); // ── (8) Reap the whole tree SCOPED, before any assertion can abort us. ── - let _ = spt(&["shell", "teardown", "DirScout", "--owner", "doyle"]); - let _ = spt(&["daemon", "stop", "--force"]); + let dir_teardown = spt(&["shell", "teardown", "DirScout", "--owner", "doyle"]); + // OBSERVE the graceful stop instead of discarding it. `daemon stop --force` + // is the step that is SUPPOSED to take the daemon and everything it + // supervises down; the leak assertion below fires when it did not. Throwing + // its result away (`let _ =`) means the one command whose failure explains + // the leak leaves no trace — and a non-zero exit here is not hypothetical: + // it is what a daemon that never came up, or one already reaped by an + // earlier arm, returns. Printed unconditionally, because a stop that + // SUCCEEDED and leaked anyway is the more interesting finding of the two. + let daemon_stop = spt(&["daemon", "stop", "--force"]); + eprintln!( + "=== resident-service teardown: dir_teardown={:?} daemon_stop={:?} ===\n\ + --- dir teardown stderr ---\n{}\n\ + --- daemon stop stdout ---\n{}\n\ + --- daemon stop stderr ---\n{}", + dir_teardown.status.code(), + daemon_stop.status.code(), + String::from_utf8_lossy(&dir_teardown.stderr), + String::from_utf8_lossy(&daemon_stop.stdout), + String::from_utf8_lossy(&daemon_stop.stderr), + ); // Every breadcrumb pid goes through the AUTHENTICATED reaper, each with the // image IT runs. A breadcrumb is a NUMBER, not an identity: the writer exits, // the OS re-mints the number (2.2 s minimum on this box), and a bare // `taskkill /F /T` on it tree-kills whoever inherited it — a concurrent test, // dying with a bare exit 1 and nothing to blame. let mut verdicts: Vec<(&'static str, Verdict)> = Vec::new(); + + // THE SUPERVISOR HOST GOES FIRST. The ServiceSet lives in the DAEMON, not in + // the brain (`daemon.rs` spawns the service host there deliberately, so a + // routine brain restart does not bounce every resident service through the + // orphan path), and `servicehost.rs`'s Relaunch arm re-mints a service pid + // when one dies un-asked. Killing a supervised service while its supervisor + // is still up therefore does not reduce the population — it ROTATES it: the + // service comes back as a NEW pid that no per-pid check in this test holds, + // which is exactly the leak shape this rig keeps catching. Order is the fix; + // the broker's `Child` handle is authenticated by construction and stays the + // mechanism, unchanged. + let _ = broker.kill(); + let _ = broker.wait(); + for (label, pid, expected, observed) in [ ("resident/boot", boot_pid, &boot_exe, boot_obs), ("resident/rel", rel_service_pid, &rel_exe, rel_obs), @@ -407,10 +440,9 @@ fn a_declared_service_rises_with_the_daemon_and_reaches_the_cli() { reap::authenticated_kill("resident/brain", brain, &spt_bin, brain_obs), )); } - // The broker is held by its `Child` handle — authenticated by construction, - // never a breadcrumb. Unchanged, and deliberately so. - let _ = broker.kill(); - let _ = broker.wait(); + // (The broker was killed ABOVE, before the services it supervises — see the + // ordering note there. It is held by its `Child` handle, authenticated by + // construction, never a breadcrumb.) // ── (8b) What SURVIVED, asked of the OS rather than of our own bookkeeping. ── // @@ -441,6 +473,18 @@ fn a_declared_service_rises_with_the_daemon_and_reaches_the_cli() { let population = sweep(); eprintln!("=== resident-service teardown: verdicts={verdicts:?} population={population:?} ==="); + // PRESERVE THE SINKS BEFORE ANY ASSERTION CAN ABORT US. `home` is a + // `TempDir`: a failing assertion unwinds, the drop deletes the directory, + // and the brain/daemon stderr that explains a leak goes with it. This copy + // is why the leak assertion below can cite a path AND paste a tail; remove + // it and the failure text starts promising evidence that no longer exists. + let evidence = common::preserve_stderr_evidence(home.path(), "resident_service_e2e"); + eprintln!( + "=== resident-service evidence: dir={} ===\n{}", + evidence.dir.display(), + evidence.note + ); + std::env::remove_var("SPT_HOME"); // ── ASSERTIONS ── @@ -674,8 +718,16 @@ fn a_declared_service_rises_with_the_daemon_and_reaches_the_cli() { after {settle_waited:?} of a {SWEEP_SETTLE_BUDGET:?} budget — went_clean=false \ at the full budget is a leak that never drained; a wait far SHORTER than the \ budget with survivors still listed means they appeared after the sweep read \ - clean, which is a different defect from termination still being in flight", - population.survivors + clean, which is a different defect from termination still being in flight\n\ + \n Each survivor above carries started_at and its CURRENT parent: a survivor \ + whose parent is this run's own daemon is a teardown-ORDER defect, one whose \ + parent is gone is an orphan, and `via=` says which selector claimed it. That \ + is the identification, in the failure text, rather than a hunt afterwards.\n\ + \n evidence copied to {} ({})\n --- daemon/brain stderr sink, last lines ---\n{}", + population.survivors, + evidence.dir.display(), + evidence.note, + evidence.tail ); assert!( population.unreadable.is_empty(),