From 0aaa2d608ec76efeb6e45aaa032c5bb8030b4872 Mon Sep 17 00:00:00 2001 From: Rain Date: Sun, 1 Sep 2024 16:14:23 -0700 Subject: [PATCH] [cargo-nextest] add `debug extract` The heuristic extraction process can be mysterious. Add this debugging command to make it less so. --- Cargo.lock | 1 + cargo-nextest/Cargo.toml | 1 + cargo-nextest/src/dispatch.rs | 188 ++++++++++++++++++++++++- cargo-nextest/src/errors.rs | 34 ++++- nextest-runner/src/reporter/helpers.rs | 22 +-- nextest-runner/src/reporter/mod.rs | 2 +- 6 files changed, 230 insertions(+), 18 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 980d78541b9..168f99ba3d1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -375,6 +375,7 @@ dependencies = [ "once_cell", "owo-colors 4.0.0", "pathdiff", + "quick-junit", "semver", "serde_json", "shell-words", diff --git a/cargo-nextest/Cargo.toml b/cargo-nextest/Cargo.toml index ac2835217d5..ed6057ac9d8 100644 --- a/cargo-nextest/Cargo.toml +++ b/cargo-nextest/Cargo.toml @@ -32,6 +32,7 @@ nextest-metadata = { version = "=0.12.0", path = "../nextest-metadata" } once_cell = "1.19.0" owo-colors.workspace = true pathdiff = { version = "0.2.1", features = ["camino"] } +quick-junit.workspace = true semver = "1.0.23" shell-words = "1.1.0" supports-color = "2.1.0" diff --git a/cargo-nextest/src/dispatch.rs b/cargo-nextest/src/dispatch.rs index 79ee7aec2a0..50578157801 100644 --- a/cargo-nextest/src/dispatch.rs +++ b/cargo-nextest/src/dispatch.rs @@ -30,9 +30,15 @@ use nextest_runner::{ partition::PartitionerBuilder, platform::{BuildPlatforms, HostPlatform, PlatformLibdir, TargetPlatform}, redact::Redactor, - reporter::{structured, FinalStatusLevel, StatusLevel, TestOutputDisplay, TestReporterBuilder}, + reporter::{ + heuristic_extract_description, highlight_end, structured, DescriptionKind, + FinalStatusLevel, StatusLevel, TestOutputDisplay, TestReporterBuilder, + }, reuse_build::{archive_to_file, ArchiveReporter, PathMapper, ReuseBuildInfo}, - runner::{configure_handle_inheritance, FinalRunStats, RunStatsFailureKind, TestRunnerBuilder}, + runner::{ + configure_handle_inheritance, ExecutionResult, FinalRunStats, RunStatsFailureKind, + TestRunnerBuilder, + }, show_config::{ShowNextestVersion, ShowTestGroupSettings, ShowTestGroups, ShowTestGroupsMode}, signal::SignalHandlerKind, target_runner::{PlatformRunner, TargetRunner}, @@ -42,10 +48,12 @@ use nextest_runner::{ }; use once_cell::sync::OnceCell; use owo_colors::{OwoColorize, Stream, Style}; +use quick_junit::XmlString; use semver::Version; use std::{ collections::BTreeSet, env::VarError, + fmt, io::{Cursor, Write}, sync::Arc, }; @@ -170,6 +178,7 @@ impl AppOpts { output_writer, ), Command::Self_ { command } => command.exec(self.common.output), + Command::Debug { command } => command.exec(self.common.output), } } } @@ -378,6 +387,15 @@ enum Command { #[clap(subcommand)] command: SelfCommand, }, + /// Debug commands + /// + /// The commands in this section are for nextest's own developers and those integrating with it + /// to debug issues. They are not part of the public API and may change at any time. + #[clap(hide = true)] + Debug { + #[clap(subcommand)] + command: DebugCommand, + }, } #[derive(Debug, Args)] @@ -1971,6 +1989,172 @@ impl SelfCommand { } } +#[derive(Debug, Subcommand)] +enum DebugCommand { + /// Show the data that nextest would extract from standard output or standard error. + /// + /// Text extraction is a heuristic process driven by a bunch of regexes and other similar logic. + /// This command shows what nextest would extract from a given input. + Extract { + /// The path to the standard output produced by the test process. + #[arg(long, required_unless_present_any = ["stderr", "combined"])] + stdout: Option, + + /// The path to the standard error produced by the test process. + #[arg(long, required_unless_present_any = ["stdout", "combined"])] + stderr: Option, + + /// The combined output produced by the test process. + #[arg(long, conflicts_with_all = ["stdout", "stderr"])] + combined: Option, + + /// The kind of output to produce. + #[arg(value_enum)] + output_format: ExtractOutputFormat, + }, +} + +impl DebugCommand { + fn exec(self, output: OutputOpts) -> Result { + let _ = output.init(); + + match self { + DebugCommand::Extract { + stdout, + stderr, + combined, + output_format, + } => { + // Either stdout + stderr or combined must be present. + if let Some(combined) = combined { + let combined = std::fs::read(&combined).map_err(|err| { + ExpectedError::DebugExtractReadError { + kind: "combined", + path: combined, + err, + } + })?; + + let description_kind = extract_description(&combined, &combined); + display_description_kind(description_kind, output_format)?; + } else { + let stdout = stdout + .map(|path| { + std::fs::read(&path).map_err(|err| { + ExpectedError::DebugExtractReadError { + kind: "stdout", + path, + err, + } + }) + }) + .transpose()? + .unwrap_or_default(); + let stderr = stderr + .map(|path| { + std::fs::read(&path).map_err(|err| { + ExpectedError::DebugExtractReadError { + kind: "stderr", + path, + err, + } + }) + }) + .transpose()? + .unwrap_or_default(); + + let description_kind = extract_description(&stdout, &stderr); + display_description_kind(description_kind, output_format)?; + } + } + } + + Ok(0) + } +} + +fn extract_description<'a>(stdout: &'a [u8], stderr: &'a [u8]) -> Option> { + // The execution result is a generic one. + heuristic_extract_description( + ExecutionResult::Fail { + abort_status: None, + leaked: false, + }, + stdout, + stderr, + ) +} + +fn display_description_kind( + kind: Option>, + output_format: ExtractOutputFormat, +) -> Result<()> { + match output_format { + ExtractOutputFormat::Raw => { + if let Some(kind) = kind { + if let Some(out) = kind.combined_subslice() { + return std::io::stdout().write_all(out.slice).map_err(|err| { + ExpectedError::DebugExtractWriteError { + format: output_format, + err, + } + }); + } + } + } + ExtractOutputFormat::JunitDescription => { + if let Some(kind) = kind { + println!( + "{}", + XmlString::new(kind.display_human().to_string()).as_str() + ); + } + } + ExtractOutputFormat::Highlight => { + if let Some(kind) = kind { + if let Some(out) = kind.combined_subslice() { + let end = highlight_end(out.slice); + return std::io::stdout() + .write_all(&out.slice[..end]) + .map_err(|err| ExpectedError::DebugExtractWriteError { + format: output_format, + err, + }); + } + } + } + } + + eprintln!("(no description found)"); + Ok(()) +} + +/// Output format for `nextest debug extract`. +#[derive(Clone, Copy, Debug, ValueEnum)] +pub enum ExtractOutputFormat { + /// Show the raw text extracted. + Raw, + + /// Show what would be put in the description field of JUnit reports. + /// + /// This is similar to `Raw`, but is valid Unicode, and strips out ANSI escape codes and other + /// invalid XML characters. + JunitDescription, + + /// Show what would be highlighted in nextest's output. + Highlight, +} + +impl fmt::Display for ExtractOutputFormat { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + match self { + Self::Raw => write!(f, "raw"), + Self::JunitDescription => write!(f, "junit-description"), + Self::Highlight => write!(f, "highlight"), + } + } +} + fn acquire_graph_data( manifest_path: Option<&Utf8Path>, target_dir: Option<&Utf8Path>, diff --git a/cargo-nextest/src/errors.rs b/cargo-nextest/src/errors.rs index b09e206122c..1e52f680a1d 100644 --- a/cargo-nextest/src/errors.rs +++ b/cargo-nextest/src/errors.rs @@ -1,6 +1,7 @@ // Copyright (c) The nextest Contributors // SPDX-License-Identifier: MIT OR Apache-2.0 +use crate::ExtractOutputFormat; use camino::Utf8PathBuf; use itertools::Itertools; use nextest_filtering::errors::FiltersetParseErrors; @@ -249,6 +250,19 @@ pub enum ExpectedError { #[from] err: FormatVersionError, }, + #[error("extract read error")] + DebugExtractReadError { + kind: &'static str, + path: Utf8PathBuf, + #[source] + err: std::io::Error, + }, + #[error("extract write error")] + DebugExtractWriteError { + format: ExtractOutputFormat, + #[source] + err: std::io::Error, + }, } impl ExpectedError { @@ -386,7 +400,8 @@ impl ExpectedError { | Self::DialoguerError { .. } | Self::SignalHandlerSetupError { .. } | Self::ShowTestGroupsError { .. } - | Self::InvalidMessageFormatVersion { .. } => NextestExitCode::SETUP_ERROR, + | Self::InvalidMessageFormatVersion { .. } + | Self::DebugExtractReadError { .. } => NextestExitCode::SETUP_ERROR, Self::ConfigParseError { err } => { // Experimental features not being enabled are their own error. match err.kind() { @@ -412,9 +427,9 @@ impl ExpectedError { Self::TestRunFailed => NextestExitCode::TEST_RUN_FAILED, Self::NoTestsRun { .. } => NextestExitCode::NO_TESTS_RUN, Self::ArchiveCreateError { .. } => NextestExitCode::ARCHIVE_CREATION_FAILED, - Self::WriteTestListError { .. } | Self::WriteEventError { .. } => { - NextestExitCode::WRITE_OUTPUT_ERROR - } + Self::WriteTestListError { .. } + | Self::WriteEventError { .. } + | Self::DebugExtractWriteError { .. } => NextestExitCode::WRITE_OUTPUT_ERROR, #[cfg(feature = "self-update")] Self::UpdateError { .. } => NextestExitCode::UPDATE_ERROR, Self::ExperimentalFeatureNotEnabled { .. } => { @@ -833,6 +848,17 @@ impl ExpectedError { log::error!("error parsing message format version"); Some(err as &dyn Error) } + Self::DebugExtractReadError { kind, path, err } => { + log::error!( + "error reading {kind} file `{}`", + path.if_supports_color(Stream::Stderr, |x| x.bold()), + ); + Some(err as &dyn Error) + } + Self::DebugExtractWriteError { format, err } => { + log::error!("error writing {format} output"); + Some(err as &dyn Error) + } }; while let Some(err) = next_error { diff --git a/nextest-runner/src/reporter/helpers.rs b/nextest-runner/src/reporter/helpers.rs index dd760a87bd2..49a20337b31 100644 --- a/nextest-runner/src/reporter/helpers.rs +++ b/nextest-runner/src/reporter/helpers.rs @@ -34,10 +34,10 @@ pub enum DescriptionKind<'a> { leaked: bool, }, - /// A stack trace was found in the output. + /// A panic message was found in the output. /// /// The output is borrowed from standard error. - StackTrace { + PanicMessage { /// The subslice of standard error that contains the stack trace. stderr_subslice: ByteSubslice<'a>, }, @@ -64,7 +64,7 @@ impl<'a> DescriptionKind<'a> { pub fn stderr_subslice(&self) -> Option> { match self { DescriptionKind::Abort { .. } => None, - DescriptionKind::StackTrace { stderr_subslice } + DescriptionKind::PanicMessage { stderr_subslice } | DescriptionKind::ErrorStr { stderr_subslice, .. } => Some(*stderr_subslice), @@ -76,7 +76,7 @@ impl<'a> DescriptionKind<'a> { pub fn stdout_subslice(&self) -> Option> { match self { DescriptionKind::Abort { .. } => None, - DescriptionKind::StackTrace { .. } => None, + DescriptionKind::PanicMessage { .. } => None, DescriptionKind::ErrorStr { .. } => None, DescriptionKind::ShouldPanic { stdout_subslice, .. @@ -88,7 +88,7 @@ impl<'a> DescriptionKind<'a> { pub fn combined_subslice(&self) -> Option> { match self { DescriptionKind::Abort { .. } => None, - DescriptionKind::StackTrace { stderr_subslice } + DescriptionKind::PanicMessage { stderr_subslice } | DescriptionKind::ErrorStr { stderr_subslice, .. } => Some(*stderr_subslice), @@ -147,7 +147,7 @@ impl fmt::Display for DescriptionKindDisplay<'_> { } Ok(()) } - DescriptionKind::StackTrace { stderr_subslice } => { + DescriptionKind::PanicMessage { stderr_subslice } => { // Strip invalid XML characters. write!(f, "{}", String::from_utf8_lossy(stderr_subslice.slice)) } @@ -177,8 +177,8 @@ pub fn heuristic_extract_description<'a>( } // Try the heuristic stack trace extraction first to try and grab more information first. - if let Some(stderr_subslice) = heuristic_stack_trace(stderr) { - return Some(DescriptionKind::StackTrace { stderr_subslice }); + if let Some(stderr_subslice) = heuristic_panic_message(stderr) { + return Some(DescriptionKind::PanicMessage { stderr_subslice }); } if let Some(stderr_subslice) = heuristic_error_str(stderr) { return Some(DescriptionKind::ErrorStr { stderr_subslice }); @@ -209,7 +209,7 @@ fn heuristic_should_panic(stdout: &[u8]) -> Option> { Some(ByteSubslice { slice: line, start }) } -fn heuristic_stack_trace(stderr: &[u8]) -> Option> { +fn heuristic_panic_message(stderr: &[u8]) -> Option> { let panicked_at_match = PANICKED_AT_REGEX.find(stderr)?; // If the previous line starts with "Error: ", grab it as well -- it contains the error with // result-based test failures. @@ -247,7 +247,7 @@ fn heuristic_error_str(stderr: &[u8]) -> Option> { /// Given a slice, find the index of the point at which highlighting should end. /// /// Returns a value in the range [0, slice.len()]. -pub(super) fn highlight_end(slice: &[u8]) -> usize { +pub fn highlight_end(slice: &[u8]) -> usize { // We want to highlight the first two lines of the output. let mut iter = slice.find_iter(b"\n"); match iter.next() { @@ -417,7 +417,7 @@ some more text at the end, followed by some newlines"#, ]; for (input, output) in tests { - let extracted = heuristic_stack_trace(input.as_bytes()) + let extracted = heuristic_panic_message(input.as_bytes()) .expect("stack trace should have been found"); assert_eq!( DisplayWrapper(extracted.slice), diff --git a/nextest-runner/src/reporter/mod.rs b/nextest-runner/src/reporter/mod.rs index e7c674638fd..5c63e2871dc 100644 --- a/nextest-runner/src/reporter/mod.rs +++ b/nextest-runner/src/reporter/mod.rs @@ -11,4 +11,4 @@ mod helpers; pub mod structured; pub use displayer::*; -pub use helpers::{heuristic_extract_description, DescriptionKind}; +pub use helpers::{heuristic_extract_description, highlight_end, DescriptionKind};