feat: say why a scenario's processes died

NEWS.md

@@ -2,6 +2,12 @@
 
 ## Unreleased
 
+- New: Outcome lines, scenario logs, and `outcomes.json` now say when a phase's process was killed by a signal, and when processes left running by the tests had to be reaped. The caught / missed / unviable / timeout classification is unchanged.
+
+- Fixed: Each cargo invocation now runs as the leader of its own process group, and that group is swept after every phase, not only after a timeout. Processes left running by a scenario's tests are `SIGTERM`ed, given a short grace period, and then `SIGKILL`ed, so they can't keep consuming memory or CPU while later mutants are tested. Unix only.
+
+- Fixed: After a timeout, cargo-mutants waits only a short grace period for the child to exit after `SIGTERM` before sending `SIGKILL`. Previously it waited indefinitely, so a process that ignored `SIGTERM`, or that had been stopped, hung the whole run.
+
 - New: `#[mutants::exclude_re("pattern")]` attribute to exclude specific mutations by regex, without disabling all mutations on the function. The attribute can be placed on functions, `impl` blocks, `trait` blocks, modules, files, and on expressions that can carry an attribute (such as `match`, struct literals, call expressions, method calls, and unary expressions). Multiple patterns can be applied. Also supported within `cfg_attr`. Requires the [mutants](https://crates.io/crates/mutants) crate version `0.0.5` or later.
 
 - Fixed: `#[mutants::skip]` (and `#[cfg_attr(..., mutants::skip)]`) is now honoured when placed on `const` and `static` items, including associated constants in `impl` and `trait` blocks. Previously the attribute was silently ignored on these items and operator mutants inside the initializer expression were still generated ([#508](https://github.com/sourcefrog/cargo-mutants/issues/508)).

book/src/timeouts.md

@@ -33,6 +33,11 @@ You can set an explicit timeouts with the `--timeout` option, also measured in s
 You can also set the test timeout as a multiple of the duration of the baseline test, with the `--timeout-multiplier` option and the `timeout_multiplier` configuration key.
 The multiplier only has an effect if the baseline is not skipped and if `--timeout` is not specified.
 
+When a timeout expires, the process is sent `SIGTERM` so that it can clean up, and then
+`SIGKILL` if it has not exited within a short grace period. A test process that ignores
+`SIGTERM`, or that has been stopped and so never receives it, therefore cannot stall the
+whole run.
+
 ## Build timeouts
 
 `const` expressions may be evaluated at compile time. In the same way that mutations can cause tests to hang, mutations to const code may potentially cause the compiler to enter an infinite loop.
@@ -45,6 +50,41 @@ In this case you can use the `--build-timeout` or `--build-timeout-multiplier` o
 
 You might also choose to skip mutants that can cause long-running const evaluation.
 
+## Leftover processes
+
+A test can leave processes running after it returns: a daemon it started, a helper it
+forgot to wait for, or a test binary that was not reaped. Those processes keep running
+— and keep allocating — while cargo-mutants moves on to the next mutant, so they can
+exhaust the machine's memory in a window where no cargo phase is running at all.
+
+To prevent this, cargo-mutants starts each cargo invocation as the leader of its own
+process group, and sweeps that group after *every* phase, not only after a timeout.
+Once the cargo process itself exits, anything left in the group is sent `SIGTERM`, given
+a short grace period, and then `SIGKILL`ed. What was reaped is recorded in the
+scenario's log, and the pids are shown at `--level=debug`.
+
+This has no effect on how a mutant is classified; it only stops work from one scenario
+leaking into the next. Windows has no process groups, and cargo-mutants does not yet use
+job objects, so this sweep is Unix-only.
+
+## Why a scenario died
+
+A mutant caught because the kernel killed its tests looks, in the summary counts, exactly
+like a mutant caught by a failing assertion. When there is more to say, cargo-mutants says
+it in parentheses on the outcome line:
+
+```
+caught   src/server.rs:88:5: replace listen -> bool with false (test killed by SIGABRT; test left 1 stray process behind (SIGKILLed: 30411)) in 2s build + 9s test
+```
+
+Two things get reported this way: the signal that killed a phase's cargo process, if it
+died by one, and anything the process group sweep had to clean up. The same information
+is written to the scenario's log and, in `mutants.out/outcomes.json`, to a `sweep` field
+on each phase result.
+
+This does not change the caught / missed / unviable / timeout classification. It only
+makes the reason visible.
+
 ## Exceptions
 
 The multiplier timeout options cannot be used when the baseline is skipped

src/cargo.rs

@@ -55,7 +55,7 @@ pub fn run_cargo(
         debug!(?encoded_rustflags);
         env.push(("CARGO_ENCODED_RUSTFLAGS".to_owned(), encoded_rustflags));
     }
-    let process_status = Process::run(
+    let (process_status, sweep) = Process::run(
         &argv,
         &env,
         build_dir.path(),
@@ -79,6 +79,7 @@ pub fn run_cargo(
         duration: start.elapsed(),
         process_status,
         argv,
+        sweep,
     })
 }
 

src/console.rs

@@ -90,6 +90,10 @@ impl Console {
             style_outcome(outcome),
             style_scenario(scenario, true),
         );
+        let death_reasons = outcome.death_reasons();
+        if !death_reasons.is_empty() {
+            write!(s, " ({})", death_reasons.join("; ")).expect("format death reasons");
+        }
         if options.show_times {
             let prs: Vec<String> = outcome
                 .phase_results()

src/outcome.rs

@@ -17,7 +17,9 @@ use tracing::warn;
 
 use crate::console::{format_duration, plural};
 use crate::exit_code::ExitCode;
-use crate::process::Exit;
+#[cfg(unix)]
+use crate::process::signal_name;
+use crate::process::{Exit, Sweep};
 use crate::{Options, Result, Scenario, output};
 
 /// What phase of running a scenario.
@@ -245,6 +247,19 @@ impl ScenarioOutcome {
             .any(|pr| pr.phase != Phase::Test && pr.process_status.is_failure())
     }
 
+    /// Say, for each phase that has something unusual to report, how its process tree
+    /// ended: killed by a signal, or leaving stray processes behind.
+    ///
+    /// This has no bearing on how the mutant is classified. It exists so that a mutant
+    /// caught because the kernel killed its tests can be told apart from one caught by a
+    /// failing assertion.
+    pub fn death_reasons(&self) -> Vec<String> {
+        self.phase_results
+            .iter()
+            .flat_map(PhaseResult::death_reasons)
+            .collect()
+    }
+
     /// True if this outcome is a caught mutant: it's a mutant and the tests failed.
     pub fn mutant_caught(&self) -> bool {
         self.scenario.is_mutant()
@@ -303,24 +318,40 @@ pub struct PhaseResult {
     pub process_status: Exit,
     /// What command was run, as an argv list.
     pub argv: Vec<String>,
+    /// What the sweep of the child's process group found and did.
+    pub sweep: Sweep,
 }
 
 impl PhaseResult {
     pub fn is_success(&self) -> bool {
         self.process_status.is_success()
     }
+
+    fn death_reasons(&self) -> Vec<String> {
+        let phase = self.phase.name();
+        let mut reasons = Vec::new();
+        #[cfg(unix)]
+        if let Exit::Signalled(signal) = self.process_status {
+            reasons.push(format!("{phase} killed by {}", signal_name(signal)));
+        }
+        if let Some(sweep) = self.sweep.describe() {
+            reasons.push(format!("{phase} {sweep}"));
+        }
+        reasons
+    }
 }
 
 impl Serialize for PhaseResult {
     fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
     where
         S: Serializer,
     {
-        let mut ss = serializer.serialize_struct("PhaseResult", 4)?;
+        let mut ss = serializer.serialize_struct("PhaseResult", 5)?;
         ss.serialize_field("phase", &self.phase)?;
         ss.serialize_field("duration", &self.duration.as_secs_f64())?;
         ss.serialize_field("process_status", &self.process_status)?;
         ss.serialize_field("argv", &self.argv)?;
+        ss.serialize_field("sweep", &self.sweep)?;
         ss.end()
     }
 }
@@ -341,10 +372,68 @@ pub enum SummaryOutcome {
 mod test {
     use std::time::Duration;
 
-    use crate::process::Exit;
+    use crate::process::{Exit, Sweep};
 
     use super::{Phase, PhaseResult, Scenario, ScenarioOutcome};
 
+    fn phase_result(phase: Phase, process_status: Exit, sweep: Sweep) -> PhaseResult {
+        PhaseResult {
+            phase,
+            duration: Duration::from_secs(1),
+            process_status,
+            argv: vec!["cargo".into(), "test".into()],
+            sweep,
+        }
+    }
+
+    fn outcome_of(phase_results: Vec<PhaseResult>) -> ScenarioOutcome {
+        ScenarioOutcome {
+            output_dir: "output".into(),
+            log_path: "log".into(),
+            diff_path: None,
+            scenario: Scenario::Baseline,
+            phase_results,
+        }
+    }
+
+    #[test]
+    fn no_death_reasons_for_an_ordinary_test_failure() {
+        let outcome = outcome_of(vec![phase_result(
+            Phase::Test,
+            Exit::Failure(101),
+            Sweep::default(),
+        )]);
+        assert_eq!(outcome.death_reasons(), Vec::<String>::new());
+    }
+
+    #[cfg(unix)]
+    #[test]
+    fn death_reasons_name_the_signal_that_killed_the_phase() {
+        let outcome = outcome_of(vec![phase_result(
+            Phase::Test,
+            Exit::Signalled(9),
+            Sweep::default(),
+        )]);
+        assert_eq!(outcome.death_reasons(), ["test killed by SIGKILL"]);
+    }
+
+    #[test]
+    fn death_reasons_name_processes_left_behind_by_the_tests() {
+        let outcome = outcome_of(vec![phase_result(
+            Phase::Test,
+            Exit::Success,
+            Sweep {
+                pids: Some(vec![101, 102]),
+                strays: true,
+                killed: true,
+            },
+        )]);
+        assert_eq!(
+            outcome.death_reasons(),
+            ["test left 2 stray processes behind (SIGKILLed: 101, 102)"]
+        );
+    }
+
     #[test]
     fn find_phase_result() {
         let outcome = ScenarioOutcome {
@@ -358,12 +447,14 @@ mod test {
                     duration: Duration::from_secs(2),
                     process_status: Exit::Success,
                     argv: vec!["cargo".into(), "build".into()],
+                    sweep: Sweep::default(),
                 },
                 PhaseResult {
                     phase: Phase::Test,
                     duration: Duration::from_secs(3),
                     process_status: Exit::Success,
                     argv: vec!["cargo".into(), "test".into()],
+                    sweep: Sweep::default(),
                 },
             ],
         };
@@ -374,6 +465,7 @@ mod test {
                 duration: Duration::from_secs(2),
                 process_status: Exit::Success,
                 argv: vec!["cargo".into(), "build".into()],
+                sweep: Sweep::default(),
             })
         );
         assert_eq!(