Add support for combined test output (to land) (#1212)

For libtest JSON emulation, we need to have a way to model combined stdout and stderr output. The best way to do this happens to be to use the same file descriptor (HANDLE on Windows) for stdout and stderr. This is pretty useful generally, and in the future we may enable support for combined test output even outside the libtest-json context. The main alternative considered was having separate fds, but selecting from them into a single giant buffer with tracking indexes into it. However, that doesn't quite work because reading from pipes is done asynchronously with the test process writing to them. This typically causes lines from stdout and stderr to be clumped with each other. If the same fd is used as in this PR, the test process writes to stdout and stderr *synchronously*, which means that the combined output is recorded in the exact order the test process generates it in. Enabling combined output does mean that we lose the ability to track outputs separately, but that's not a huge deal.
nextest-rs · Jan 9, 2024 · 781ad9f · 781ad9f
1 parent 39600e7
commit 781ad9f
Show file tree

Hide file tree

Showing 28 changed files with 1,175 additions and 284 deletions.
diff --git a/.gitignore b/.gitignore
@@ -1 +1,3 @@
 /target
+# Ignore non-reviewed insta snapshots
+*.snap.new
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/Cargo.toml b/Cargo.toml
@@ -11,6 +11,7 @@ members = [
 ]
 
 [workspace.dependencies]
+bstr = { version = "1.9.0", default-features = false, features = ["std"] }
 globset = "0.4.14"
 nextest-metadata = { version = "0.10.0", path = "nextest-metadata" }
 nextest-workspace-hack = "0.1.0"

diff --git a/cargo-nextest/src/dispatch.rs b/cargo-nextest/src/dispatch.rs
@@ -741,13 +741,16 @@ pub struct TestRunnerOpts {
 }
 
 impl TestRunnerOpts {
-    fn to_builder(&self, no_capture: bool) -> Option<TestRunnerBuilder> {
+    fn to_builder(
+        &self,
+        cap_strat: nextest_runner::test_output::CaptureStrategy,
+    ) -> Option<TestRunnerBuilder> {
         if self.no_run {
             return None;
         }
 
         let mut builder = TestRunnerBuilder::default();
-        builder.set_no_capture(no_capture);
+        builder.set_capture_strategy(cap_strat);
         if let Some(retries) = self.retries {
             builder.set_retries(RetryPolicy::new_without_delay(retries));
         }
@@ -1546,6 +1549,15 @@ impl App {
                 )?)
             }
         };
+        use nextest_runner::test_output::CaptureStrategy;
+
+        let cap_strat = if no_capture {
+            CaptureStrategy::None
+        } else if matches!(reporter_opts.message_format, MessageFormat::Human) {
+            CaptureStrategy::Split
+        } else {
+            CaptureStrategy::Combined
+        };
 
         let filter_exprs = self.build_filtering_expressions()?;
         let test_filter_builder = self.build_filter.make_test_filter_builder(filter_exprs)?;
@@ -1578,7 +1590,7 @@ impl App {
         }
 
         let handler = SignalHandlerKind::Standard;
-        let runner_builder = match runner_opts.to_builder(no_capture) {
+        let runner_builder = match runner_opts.to_builder(cap_strat) {
             Some(runner_builder) => runner_builder,
             None => {
                 // This means --no-run was passed in. Exit.

diff --git a/fixtures/nextest-tests-junit.xml b/fixtures/nextest-tests-junit.xml
@@ -1,15 +1,15 @@
 <?xml version="1.0" encoding="UTF-8"?>
-<testsuites name="nextest-run" tests="3" failures="1" errors="0" uuid="03540265-7c54-4df7-a49e-2b0f44422a24" timestamp="2024-01-09T07:46:35.523+00:00" time="0.022">
+<testsuites name="nextest-run" tests="3" failures="1" errors="0" uuid="45c50042-482e-477e-88a2-60cfcc3eaf95" timestamp="2024-01-09T07:50:12.664+00:00" time="0.023">
     <testsuite name="nextest-tests::basic" tests="3" disabled="0" errors="0" failures="1">
-        <testcase name="test_cwd" classname="nextest-tests::basic" timestamp="2024-01-09T07:46:35.524+00:00" time="0.004">
+        <testcase name="test_cwd" classname="nextest-tests::basic" timestamp="2024-01-09T07:50:12.665+00:00" time="0.004">
         </testcase>
-        <testcase name="test_failure_assert" classname="nextest-tests::basic" timestamp="2024-01-09T07:46:35.524+00:00" time="0.004">
+        <testcase name="test_failure_assert" classname="nextest-tests::basic" timestamp="2024-01-09T07:50:12.665+00:00" time="0.004">
             <failure type="test failure">thread &apos;test_failure_assert&apos; panicked at tests/basic.rs:19:5:
 assertion `left == right` failed: this is an assertion
   left: 4
  right: 5
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace</failure>
-            <rerunFailure timestamp="2024-01-09T07:46:35.529+00:00" time="0.004" type="test failure">thread &apos;test_failure_assert&apos; panicked at tests/basic.rs:19:5:
+            <rerunFailure timestamp="2024-01-09T07:50:12.670+00:00" time="0.004" type="test failure">thread &apos;test_failure_assert&apos; panicked at tests/basic.rs:19:5:
 assertion `left == right` failed: this is an assertion
   left: 4
  right: 5
@@ -33,7 +33,7 @@ assertion `left == right` failed: this is an assertion
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
 </system-err>
             </rerunFailure>
-            <rerunFailure timestamp="2024-01-09T07:46:35.534+00:00" time="0.004" type="test failure">thread &apos;test_failure_assert&apos; panicked at tests/basic.rs:19:5:
+            <rerunFailure timestamp="2024-01-09T07:50:12.676+00:00" time="0.004" type="test failure">thread &apos;test_failure_assert&apos; panicked at tests/basic.rs:19:5:
 assertion `left == right` failed: this is an assertion
   left: 4
  right: 5
@@ -76,8 +76,8 @@ assertion `left == right` failed: this is an assertion
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
 </system-err>
         </testcase>
-        <testcase name="test_flaky_mod_4" classname="nextest-tests::basic" timestamp="2024-01-09T07:46:35.541+00:00" time="0.004">
-            <flakyFailure timestamp="2024-01-09T07:46:35.524+00:00" time="0.004" type="test failure">thread &apos;test_flaky_mod_4&apos; panicked at tests/basic.rs:43:9:
+        <testcase name="test_flaky_mod_4" classname="nextest-tests::basic" timestamp="2024-01-09T07:50:12.683+00:00" time="0.004">
+            <flakyFailure timestamp="2024-01-09T07:50:12.665+00:00" time="0.004" type="test failure">thread &apos;test_flaky_mod_4&apos; panicked at tests/basic.rs:43:9:
 Failed because attempt 1 % 4 != 0
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
                 <system-out>
@@ -97,7 +97,7 @@ Failed because attempt 1 % 4 != 0
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
 </system-err>
             </flakyFailure>
-            <flakyFailure timestamp="2024-01-09T07:46:35.529+00:00" time="0.004" type="test failure">thread &apos;test_flaky_mod_4&apos; panicked at tests/basic.rs:43:9:
+            <flakyFailure timestamp="2024-01-09T07:50:12.671+00:00" time="0.004" type="test failure">thread &apos;test_flaky_mod_4&apos; panicked at tests/basic.rs:43:9:
 Failed because attempt 2 % 4 != 0
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
                 <system-out>
@@ -117,7 +117,7 @@ Failed because attempt 2 % 4 != 0
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
 </system-err>
             </flakyFailure>
-            <flakyFailure timestamp="2024-01-09T07:46:35.534+00:00" time="0.006" type="test failure">thread &apos;test_flaky_mod_4&apos; panicked at tests/basic.rs:43:9:
+            <flakyFailure timestamp="2024-01-09T07:50:12.676+00:00" time="0.005" type="test failure">thread &apos;test_flaky_mod_4&apos; panicked at tests/basic.rs:43:9:
 Failed because attempt 3 % 4 != 0
 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
                 <system-out>

diff --git a/integration-tests/tests/integration/fixtures.rs b/integration-tests/tests/integration/fixtures.rs
@@ -439,7 +439,10 @@ pub fn check_run_output(stderr: &[u8], relocated: bool) {
 
     for (result, name) in expected {
         let reg = make_check_result_regex(*result, name);
-        assert!(reg.is_match(&output), "{name}: result didn't match");
+        assert!(
+            reg.is_match(&output),
+            "{name}: result didn't match\n\n--- output ---\n{output}\n--- end output ---"
+        );
     }
 
     let summary_reg = if relocated {

diff --git a/nextest-runner/Cargo.toml b/nextest-runner/Cargo.toml
@@ -16,12 +16,16 @@ atomicwrites = "0.4.3"
 aho-corasick = "1.1.2"
 async-scoped = { version = "0.8.0", features = ["use-tokio"] }
 future-queue = "0.3.0"
+bstr.workspace = true
 bytes = "1.5.0"
 camino = { version = "1.1.6", features = ["serde1"] }
 camino-tempfile = "1.1.1"
 # config's "preserve_order" feature is needed for preserving the order of
 # setup scripts in .config/nextest.toml.
-config = { version = "0.13.4", default-features = false, features = ["toml", "preserve_order"] }
+config = { version = "0.13.4", default-features = false, features = [
+    "toml",
+    "preserve_order",
+] }
 cargo_metadata = "0.18.1"
 cfg-if = "1.0.0"
 chrono = "0.4.31"
@@ -40,11 +44,12 @@ indicatif = "0.17.7"
 is_ci = "1.1.1"
 itertools = "0.12.0"
 log = "0.4.20"
-rand = "0.8.5"
+memchr = "2.6"
 miette = "5.10.0"
 once_cell = "1.19.0"
 owo-colors = "4.0.0"
 pin-project-lite = "0.2.13"
+rand = "0.8.5"
 regex = "1.10.2"
 semver = "1.0.21"
 serde = { version = "1.0.195", features = ["derive"] }
@@ -106,11 +111,13 @@ nix = { version = "0.27.1", default-features = false, features = ["signal"] }
 # https://docs.rs/winapi/0.3.9/src/winapi/lib.rs.html#35-37
 # Otherwise nextest-runner runs into compilation issues with win32job.
 winapi = { version = "0.3.9", features = ["std"] }
-windows = { version = "0.52.0", features = [
+windows-sys = { version = "0.52.0", features = [
     "Win32_Foundation",
     "Win32_Globalization",
+    "Win32_Security",
     "Win32_System_Console",
     "Win32_System_JobObjects",
+    "Win32_System_Pipes",
 ] }
 win32job = "1.0.2"
 dunce = "1.0.4"
@@ -131,6 +138,7 @@ self_update = { version = "0.39.0", optional = true }
 color-eyre = { version = "0.6.2", default-features = false }
 duct = "0.13.7"
 indoc = "2.0.4"
+insta = { version = "1.34.0", default-features = false }
 maplit = "1.0.2"
 pathdiff = { version = "0.2.1", features = ["camino"] }
 pretty_assertions = "1.4.0"

diff --git a/nextest-runner/src/cargo_config/env.rs b/nextest-runner/src/cargo_config/env.rs
@@ -156,7 +156,7 @@ pub fn relative_dir_for(config_path: &Utf8Path) -> Option<&Utf8Path> {
 mod imp {
     use super::*;
     use std::{borrow::Borrow, cmp, ffi::OsStr, os::windows::prelude::OsStrExt};
-    use windows::Win32::Globalization::{
+    use windows_sys::Win32::Globalization::{
         CompareStringOrdinal, CSTR_EQUAL, CSTR_GREATER_THAN, CSTR_LESS_THAN,
     };
 
@@ -203,7 +203,13 @@ mod imp {
     impl Ord for EnvKey {
         fn cmp(&self, other: &Self) -> cmp::Ordering {
             unsafe {
-                let result = CompareStringOrdinal(&self.utf16, &other.utf16, true);
+                let result = CompareStringOrdinal(
+                    self.utf16.as_ptr(),
+                    self.utf16.len() as _,
+                    other.utf16.as_ptr(),
+                    other.utf16.len() as _,
+                    1, /* ignore case */
+                );
                 match result {
                     CSTR_LESS_THAN => cmp::Ordering::Less,
                     CSTR_EQUAL => cmp::Ordering::Equal,

diff --git a/nextest-runner/src/errors.rs b/nextest-runner/src/errors.rs
@@ -759,7 +759,7 @@ pub enum ConfigureHandleInheritanceError {
     /// An error occurred. This can only happen on Windows.
     #[cfg(windows)]
     #[error("error configuring handle inheritance")]
-    WindowsError(#[from] windows::core::Error),
+    WindowsError(#[from] std::io::Error),
 }
 
 /// An error that occurs while building the test runner.

diff --git a/nextest-runner/src/helpers.rs b/nextest-runner/src/helpers.rs
@@ -194,8 +194,7 @@ pub(crate) fn extract_abort_status(exit_status: ExitStatus) -> Option<AbortStatu
             exit_status.signal().map(AbortStatus::UnixSignal)
         } else if #[cfg(windows)] {
             exit_status.code().and_then(|code| {
-                let exception = windows::Win32::Foundation::NTSTATUS(code);
-                exception.is_err().then(|| AbortStatus::WindowsNtStatus(exception))
+                (code < 0).then(|| AbortStatus::WindowsNtStatus(code))
             })
         } else {
             None
@@ -226,19 +225,18 @@ pub(crate) fn signal_str(signal: i32) -> Option<&'static str> {
 }
 
 #[cfg(windows)]
-pub(crate) fn display_nt_status(nt_status: windows::Win32::Foundation::NTSTATUS) -> String {
+pub(crate) fn display_nt_status(nt_status: windows_sys::Win32::Foundation::NTSTATUS) -> String {
     // Convert the NTSTATUS to a Win32 error code.
-    let win32_code = unsafe { windows::Win32::Foundation::RtlNtStatusToDosError(nt_status) };
+    let win32_code = unsafe { windows_sys::Win32::Foundation::RtlNtStatusToDosError(nt_status) };
 
-    if win32_code == windows::Win32::Foundation::ERROR_MR_MID_NOT_FOUND.0 {
+    if win32_code == windows_sys::Win32::Foundation::ERROR_MR_MID_NOT_FOUND {
         // The Win32 code was not found.
-        let nt_status = nt_status.0;
         return format!("{nt_status:#x} ({nt_status})");
     }
 
     return format!(
         "{:#x}: {}",
-        nt_status.0,
+        nt_status,
         io::Error::from_raw_os_error(win32_code as i32)
     );
 }

diff --git a/nextest-runner/src/lib.rs b/nextest-runner/src/lib.rs
@@ -27,6 +27,7 @@ pub mod signal;
 pub mod target_runner;
 mod test_command;
 pub mod test_filter;
+pub mod test_output;
 mod time;
 #[cfg(feature = "self-update")]
 pub mod update;