From a50803cce02442689191c92151e2d9adb14af1a6 Mon Sep 17 00:00:00 2001 From: Rain Date: Fri, 26 Jan 2024 13:40:34 -0800 Subject: [PATCH] [nextest-runner] initial support for recording runs Gated behind an environment variable. --- Cargo.lock | 49 +- cargo-nextest/src/dispatch.rs | 61 +- cargo-nextest/src/errors.rs | 10 + nextest-metadata/src/test_list.rs | 1 + nextest-runner/Cargo.toml | 6 +- nextest-runner/src/config/config_impl.rs | 61 +- nextest-runner/src/config/identifier.rs | 4 +- nextest-runner/src/config/scripts.rs | 11 +- nextest-runner/src/errors.rs | 137 ++ nextest-runner/src/lib.rs | 1 + nextest-runner/src/reporter.rs | 30 +- nextest-runner/src/reporter/structured.rs | 42 +- .../src/reporter/structured/recorder.rs | 132 ++ nextest-runner/src/run_store.rs | 1177 +++++++++++++++++ nextest-runner/src/runner.rs | 34 +- nextest-runner/src/time/stopwatch.rs | 4 + workspace-hack/Cargo.toml | 4 +- 17 files changed, 1719 insertions(+), 45 deletions(-) create mode 100644 nextest-runner/src/reporter/structured/recorder.rs create mode 100644 nextest-runner/src/run_store.rs diff --git a/Cargo.lock b/Cargo.lock index 846692413c9..2ffaf72ebed 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -441,6 +441,7 @@ dependencies = [ "iana-time-zone", "js-sys", "num-traits", + "serde", "wasm-bindgen", "windows-targets 0.52.0", ] @@ -916,6 +917,16 @@ dependencies = [ "percent-encoding", ] +[[package]] +name = "fs4" +version = "0.7.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "29f9df8a11882c4e3335eb2d18a0137c505d9ca927470b0cac9c6f0ae07d28f7" +dependencies = [ + "rustix", + "windows-sys 0.48.0", +] + [[package]] name = "future-queue" version = "0.3.0" @@ -1691,6 +1702,7 @@ dependencies = [ "duct", "dunce", "either", + "fs4", "future-queue", "futures", "guppy", @@ -1748,7 +1760,8 @@ dependencies = [ "winapi", "windows-sys 0.52.0", "xxhash-rust", - "zstd", + "zip", + "zstd 0.13.0", ] [[package]] @@ -3297,6 +3310,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "f00cc9702ca12d3c81455259621e676d0f7251cec66a21e98fe2e9a37db93b2a" dependencies = [ "getrandom", + "serde", ] [[package]] @@ -3780,6 +3794,18 @@ version = "1.7.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "525b4ec142c6b68a2d10f01f7bbf6755599ca3f81ea53b8431b7dd348f5fdb2d" +[[package]] +name = "zip" +version = "0.6.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "760394e246e4c28189f19d488c058bf16f564016aefac5d32bb1f3b51d5e9261" +dependencies = [ + "byteorder", + "crc32fast", + "crossbeam-utils", + "zstd 0.11.2+zstd.1.5.2", +] + [[package]] name = "zipsign-api" version = "0.1.1" @@ -3791,13 +3817,32 @@ dependencies = [ "thiserror", ] +[[package]] +name = "zstd" +version = "0.11.2+zstd.1.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "20cc960326ece64f010d2d2107537f26dc589a6573a316bd5b1dba685fa5fde4" +dependencies = [ + "zstd-safe 5.0.2+zstd.1.5.2", +] + [[package]] name = "zstd" version = "0.13.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "bffb3309596d527cfcba7dfc6ed6052f1d39dfbd7c867aa2e865e4a449c10110" dependencies = [ - "zstd-safe", + "zstd-safe 7.0.0", +] + +[[package]] +name = "zstd-safe" +version = "5.0.2+zstd.1.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1d2a5585e04f9eea4b2a3d1eca508c4dee9592a89ef6f450c11719da0726f4db" +dependencies = [ + "libc", + "zstd-sys", ] [[package]] diff --git a/cargo-nextest/src/dispatch.rs b/cargo-nextest/src/dispatch.rs index a01bccd5e91..ddfc38e1614 100644 --- a/cargo-nextest/src/dispatch.rs +++ b/cargo-nextest/src/dispatch.rs @@ -30,11 +30,13 @@ use nextest_runner::{ platform::BuildPlatforms, reporter::{structured, FinalStatusLevel, StatusLevel, TestOutputDisplay, TestReporterBuilder}, reuse_build::{archive_to_file, ArchiveReporter, MetadataOrPath, PathMapper, ReuseBuildInfo}, + run_store::RunStore, runner::{configure_handle_inheritance, RunStatsFailureKind, TestRunnerBuilder}, show_config::{ShowNextestVersion, ShowTestGroupSettings, ShowTestGroups, ShowTestGroupsMode}, signal::SignalHandlerKind, target_runner::{PlatformRunner, TargetRunner}, test_filter::{RunIgnored, TestFilterBuilder}, + test_output::CaptureStrategy, }; use once_cell::sync::OnceCell; use owo_colors::{OwoColorize, Stream, Style}; @@ -743,10 +745,7 @@ pub struct TestRunnerOpts { } impl TestRunnerOpts { - fn to_builder( - &self, - cap_strat: nextest_runner::test_output::CaptureStrategy, - ) -> Option { + fn to_builder(&self, cap_strat: CaptureStrategy) -> Option { if self.no_run { return None; } @@ -1557,7 +1556,6 @@ impl App { structured_reporter.set_libtest(libtest); } }; - use nextest_runner::test_output::CaptureStrategy; let cap_strat = if no_capture { CaptureStrategy::None @@ -1584,19 +1582,6 @@ impl App { let output = output_writer.reporter_output(); let profile = profile.apply_build_platforms(&build_platforms); - let mut reporter = reporter_opts - .to_builder(no_capture) - .set_verbose(self.base.output.verbose) - .build(&test_list, &profile, output, structured_reporter); - if self - .base - .output - .color - .should_colorize(supports_color::Stream::Stderr) - { - reporter.colorize(); - } - let handler = SignalHandlerKind::Standard; let runner_builder = match runner_opts.to_builder(cap_strat) { Some(runner_builder) => runner_builder, @@ -1615,11 +1600,51 @@ impl App { target_runner.clone(), )?; + // Start recording runs if the environment variable is set. + { + const EXPERIMENTAL_ENV: &str = "NEXTEST_EXPERIMENTAL_RECORD_RUNS"; + if std::env::var(EXPERIMENTAL_ENV).as_deref() == Ok("1") { + // For the record reporter, use the global store dir to share runs across profiles. + let store = RunStore::new(profile.global_store_dir()) + .map_err(|err| ExpectedError::RunRecordError { err })?; + let locked_store = store + .lock_exclusive() + .map_err(|err| ExpectedError::RunRecordError { err })?; + let recorder = locked_store + .create_run_recorder( + runner.run_id(), + self.base.current_version.clone(), + runner.started_at().fixed_offset(), + ) + .map_err(|err| ExpectedError::RunRecordError { err })?; + + let record = structured::RecordReporter::new(recorder); + structured_reporter.set_record(record); + } + } + + let mut reporter = reporter_opts + .to_builder(no_capture) + .set_verbose(self.base.output.verbose) + .build(&test_list, &profile, output, structured_reporter); + if self + .base + .output + .color + .should_colorize(supports_color::Stream::Stderr) + { + reporter.colorize(); + } + configure_handle_inheritance(no_capture)?; + reporter.report_meta(&self.base.cargo_metadata_json, &test_list); + let run_stats = runner.try_execute(|event| { // Write and flush the event. reporter.report_event(event) })?; + reporter.finish()?; + self.base .check_version_config_final(version_only_config.nextest_version())?; if !run_stats.is_success() { diff --git a/cargo-nextest/src/errors.rs b/cargo-nextest/src/errors.rs index ac00dc4af05..fb1a7e853af 100644 --- a/cargo-nextest/src/errors.rs +++ b/cargo-nextest/src/errors.rs @@ -141,6 +141,11 @@ pub enum ExpectedError { #[from] err: FromMessagesError, }, + #[error("error recording test run")] + RunRecordError { + #[source] + err: RunStoreError, + }, #[error("create test list error")] CreateTestListError { #[source] @@ -386,6 +391,7 @@ impl ExpectedError { | Self::TestFilterBuilderError { .. } | Self::UnknownHostPlatform { .. } | Self::ArgumentFileReadError { .. } + | Self::RunRecordError { .. } | Self::UnknownArchiveFormat { .. } | Self::ArchiveExtractError { .. } | Self::RustBuildMetaParseError { .. } @@ -700,6 +706,10 @@ impl ExpectedError { log::error!("failed to parse messages generated by Cargo"); Some(err as &dyn Error) } + Self::RunRecordError { err } => { + log::error!("error recording run"); + Some(err as &dyn Error) + } Self::CreateTestListError { err } => { log::error!("creating test list failed"); Some(err as &dyn Error) diff --git a/nextest-metadata/src/test_list.rs b/nextest-metadata/src/test_list.rs index 909a9fd3696..5d9a49cf26f 100644 --- a/nextest-metadata/src/test_list.rs +++ b/nextest-metadata/src/test_list.rs @@ -146,6 +146,7 @@ impl TestListSummary { rust_suites: BTreeMap::new(), } } + /// Parse JSON output from `cargo nextest list --message-format json`. pub fn parse_json(json: impl AsRef) -> Result { serde_json::from_str(json.as_ref()) diff --git a/nextest-runner/Cargo.toml b/nextest-runner/Cargo.toml index b4d06c1c886..6ad1535a5cb 100644 --- a/nextest-runner/Cargo.toml +++ b/nextest-runner/Cargo.toml @@ -28,11 +28,12 @@ config = { version = "0.13.4", default-features = false, features = [ ] } cargo_metadata = "0.18.1" cfg-if = "1.0.0" -chrono = "0.4.33" +chrono = { version = "0.4.33", features = ["serde"] } debug-ignore = "1.0.5" display-error-chain = "0.2.0" either = "1.9.0" futures = "0.3.30" +fs4 = "0.7.0" guppy = "0.17.4" # Used to find the cargo root directory, which is needed in case the user has # added a config.toml there @@ -77,6 +78,7 @@ tokio = { version = "1.35.1", features = [ toml = "0.8.8" toml_edit = { version = "0.21.0", features = ["serde"] } xxhash-rust = { version = "0.8.8", features = ["xxh64"] } +zip = { version = "0.6.6", default-features = false, features = ["zstd"] } zstd = { version = "0.13.0", features = ["zstdmt"] } ### @@ -93,7 +95,7 @@ self_update = { version = "0.39.0", optional = true, default-features = false, f nextest-filtering = { version = "0.7.1", path = "../nextest-filtering" } nextest-metadata = { version = "0.10.0", path = "../nextest-metadata" } quick-junit = { version = "0.3.5", path = "../quick-junit" } -uuid = { version = "1.7.0", features = ["v4"] } +uuid = { version = "1.7.0", features = ["v4", "serde"] } console-subscriber = { version = "0.2.0", optional = true } unicode-ident = "1.0.12" unicode-normalization = "0.1.22" diff --git a/nextest-runner/src/config/config_impl.rs b/nextest-runner/src/config/config_impl.rs index b8496beac94..dcff9f2e45a 100644 --- a/nextest-runner/src/config/config_impl.rs +++ b/nextest-runner/src/config/config_impl.rs @@ -76,10 +76,20 @@ impl NextestConfig { /// The name of the default profile used for miri. pub const DEFAULT_MIRI_PROFILE: &'static str = "default-miri"; + /// The name of the global store directory. + /// + /// This name starts with "default-" because that's the namespace reserved by nextest. + pub const GLOBAL_STORE_DIR: &'static str = "default-global"; + /// A list containing the names of the Nextest defined reserved profile names. pub const DEFAULT_PROFILES: &'static [&'static str] = &[Self::DEFAULT_PROFILE, Self::DEFAULT_MIRI_PROFILE]; + /// A list containing the names of other reserved profile names. + /// + /// These names, if used in the config section, will cause an error to happen. + pub const RESERVED_PROFILE_NAMES: &'static [&'static str] = &[Self::GLOBAL_STORE_DIR]; + /// Reads the nextest config from the given file, or if not specified from `.config/nextest.toml` /// in the workspace root. /// @@ -370,6 +380,19 @@ impl NextestConfig { let this_config = this_config.into_config_impl(); + let reserved_profiles_used: BTreeSet<_> = this_config + .all_profiles() + .filter(|&p| NextestConfig::RESERVED_PROFILE_NAMES.contains(&p)) + .map(|p| p.to_owned()) + .collect(); + if !reserved_profiles_used.is_empty() { + return Err(ConfigParseError::new( + config_file, + tool, + ConfigParseErrorKind::ReservedProfileNamesUsed(reserved_profiles_used), + )); + } + let unknown_default_profiles: Vec<_> = this_config .all_profiles() .filter(|p| p.starts_with("default-") && !NextestConfig::DEFAULT_PROFILES.contains(p)) @@ -509,8 +532,9 @@ impl NextestConfig { let custom_profile = self.inner.get_profile(name)?; // The profile was found: construct the NextestProfile. - let mut store_dir = self.workspace_root.join(&self.inner.store.dir); - store_dir.push(name); + let abs_store_dir = self.workspace_root.join(&self.inner.store.dir); + let global_store_dir = abs_store_dir.join(NextestConfig::GLOBAL_STORE_DIR); + let store_dir = abs_store_dir.join(name); // Grab the compiled data as well. let compiled_data = self @@ -523,6 +547,7 @@ impl NextestConfig { Ok(NextestProfile { name: name.to_owned(), + global_store_dir, store_dir, default_profile: &self.inner.default_profile, custom_profile, @@ -575,6 +600,7 @@ pub struct FinalConfig { #[derive(Clone, Debug)] pub struct NextestProfile<'cfg, State = FinalConfig> { name: String, + global_store_dir: Utf8PathBuf, store_dir: Utf8PathBuf, default_profile: &'cfg DefaultProfileImpl, custom_profile: Option<&'cfg CustomProfileImpl>, @@ -590,6 +616,11 @@ impl<'cfg, State> NextestProfile<'cfg, State> { &self.name } + /// Returns the global store directory. + pub fn global_store_dir(&self) -> &Utf8Path { + &self.global_store_dir + } + /// Returns the absolute profile-specific store directory. pub fn store_dir(&self) -> &Utf8Path { &self.store_dir @@ -620,6 +651,7 @@ impl<'cfg> NextestProfile<'cfg, PreBuildPlatform> { let compiled_data = self.compiled_data.apply_build_platforms(build_platforms); NextestProfile { name: self.name, + global_store_dir: self.global_store_dir, store_dir: self.store_dir, default_profile: self.default_profile, custom_profile: self.custom_profile, @@ -1026,6 +1058,31 @@ mod tests { .expect("default profile should exist"); } + #[test] + fn reserved_profile_name() { + let config_contents = r#" + [profile.default-global] + retries = 3 + "#; + + let workspace_dir = tempdir().unwrap(); + + let graph = temp_workspace(workspace_dir.path(), config_contents); + let workspace_root = graph.workspace().root(); + let error = + NextestConfig::from_sources(workspace_root, &graph, None, [], &BTreeSet::default()) + .expect_err("this should error out"); + assert!( + matches!( + error.kind(), + ConfigParseErrorKind::ReservedProfileNamesUsed(names) + if names == &maplit::btreeset! { "default-global".to_owned() } + ), + "expected config.kind ({}) to be ReservedProfileNamesUsed", + error.kind(), + ); + } + #[test] fn ignored_keys() { let config_contents = r#" diff --git a/nextest-runner/src/config/identifier.rs b/nextest-runner/src/config/identifier.rs index 1b34db7fac7..cb150eb4b7b 100644 --- a/nextest-runner/src/config/identifier.rs +++ b/nextest-runner/src/config/identifier.rs @@ -2,6 +2,7 @@ // SPDX-License-Identifier: MIT OR Apache-2.0 use crate::errors::InvalidIdentifier; +use serde::Serialize; use smol_str::SmolStr; use std::fmt; use unicode_normalization::{is_nfc_quick, IsNormalized, UnicodeNormalization}; @@ -13,7 +14,8 @@ use unicode_normalization::{is_nfc_quick, IsNormalized, UnicodeNormalization}; /// * ensuring that it is of the form (XID_Start)(XID_Continue | -)* /// /// Identifiers can also be tool identifiers, which are of the form "@tool:tool-name:identifier". -#[derive(Clone, Debug, PartialEq, Eq, PartialOrd, Ord, Hash)] +#[derive(Clone, Debug, PartialEq, Eq, PartialOrd, Ord, Hash, Serialize)] +#[serde(transparent)] pub struct ConfigIdentifier(SmolStr); impl ConfigIdentifier { diff --git a/nextest-runner/src/config/scripts.rs b/nextest-runner/src/config/scripts.rs index 6869b981a28..9ea308fe488 100644 --- a/nextest-runner/src/config/scripts.rs +++ b/nextest-runner/src/config/scripts.rs @@ -19,7 +19,7 @@ use camino_tempfile::Utf8TempPath; use guppy::graph::{cargo::BuildPlatform, PackageGraph}; use indexmap::IndexMap; use nextest_filtering::{FilteringExpr, TestQuery}; -use serde::{de::Error, Deserialize}; +use serde::{de::Error, Deserialize, Serialize}; use smol_str::SmolStr; use std::{ collections::{BTreeMap, HashMap, HashSet}, @@ -28,6 +28,7 @@ use std::{ time::Duration, }; use tokio::io::{AsyncBufReadExt, BufReader}; +use xxhash_rust::xxh3; /// Data about setup scripts, returned by a [`NextestProfile`]. pub struct SetupScripts<'profile> { @@ -425,7 +426,8 @@ impl CompiledProfileScripts { } /// The name of a configuration script. -#[derive(Clone, Debug, Eq, PartialEq, Hash, PartialOrd, Ord)] +#[derive(Clone, Debug, Eq, PartialEq, Hash, PartialOrd, Ord, Serialize)] +#[serde(transparent)] pub struct ScriptId(pub ConfigIdentifier); impl ScriptId { @@ -444,6 +446,11 @@ impl ScriptId { pub(super) fn as_str(&self) -> &str { self.0.as_str() } + + pub(crate) fn to_hex_digest(&self) -> String { + let digest = xxh3::xxh3_64(self.0.as_str().as_bytes()); + format!("{:016x}", digest) + } } impl<'de> Deserialize<'de> for ScriptId { diff --git a/nextest-runner/src/errors.rs b/nextest-runner/src/errors.rs index 0c555ffb5b0..5af43621383 100644 --- a/nextest-runner/src/errors.rs +++ b/nextest-runner/src/errors.rs @@ -90,6 +90,11 @@ pub enum ConfigParseErrorKind { /// An error occurred while deserializing the config (version only). #[error(transparent)] VersionOnlyDeserializeError(Box>), + + /// One or more reserved profile names were used. + #[error("reserved profile names used: {}", .0.iter().join(", "))] + ReservedProfileNamesUsed(BTreeSet), + /// Errors occurred while parsing compiled data. #[error("error parsing compiled data (destructure this variant for more details)")] CompiledDataParseError(Vec), @@ -1207,6 +1212,138 @@ pub enum ShowTestGroupsError { }, } +/// An error occurred while managing the run store. +#[allow(missing_docs)] +#[derive(Debug, Error)] +pub enum RunStoreError { + #[error("error creating run directory `{run_dir}`")] + RunDirCreate { + run_dir: Utf8PathBuf, + #[source] + error: std::io::Error, + }, + + #[error("error acquiring lock on `{path}`")] + FileLock { + path: Utf8PathBuf, + #[source] + error: std::io::Error, + }, + + #[error("error reading run list from `{path}`")] + RunListRead { + path: Utf8PathBuf, + #[source] + error: std::io::Error, + }, + + #[error("error deserializing run list from `{path}`")] + RunListDeserialize { + path: Utf8PathBuf, + #[source] + error: serde_json::Error, + }, + + #[error("error serializing run list to `{path}`")] + RunListSerialize { + path: Utf8PathBuf, + #[source] + error: serde_json::Error, + }, + + #[error("error serializing test list")] + TestListSerialize { + #[source] + error: serde_json::Error, + }, + + #[error("error serializing test event")] + TestEventSerialize { + #[source] + error: serde_json::Error, + }, + + #[error("error writing run list to `{path}`")] + RunListWrite { + path: Utf8PathBuf, + #[source] + error: atomicwrites::Error, + }, + + #[error("error writing to store at `{store_path}`")] + StoreWrite { + store_path: Utf8PathBuf, + #[source] + error: StoreWriterError, + }, + + #[error("error creating run log at `{path}`")] + RunLogCreate { + path: Utf8PathBuf, + #[source] + error: std::io::Error, + }, + + #[error("error writing to run log at `{path}`")] + RunLogWrite { + path: Utf8PathBuf, + #[source] + error: std::io::Error, + }, + + #[error("error flushing run log at `{path}`")] + RunLogFlush { + path: Utf8PathBuf, + #[source] + error: std::io::Error, + }, +} + +/// An error occurred while writing to a zip store. +#[allow(missing_docs)] +#[derive(Debug, Error)] +pub enum StoreWriterError { + #[error("error creating store")] + Create { + #[source] + error: std::io::Error, + }, + + #[error("error creating path `{path}` in store")] + StartFile { + path: Utf8PathBuf, + #[source] + error: zip::result::ZipError, + }, + + #[error("error writing to path `{path}` in store")] + Write { + path: Utf8PathBuf, + #[source] + error: std::io::Error, + }, + + #[error("error finalizing store")] + Finish { + #[source] + error: zip::result::ZipError, + }, + + #[error("error flushing store")] + Flush { + #[source] + error: std::io::Error, + }, +} + +/// An error occurred in an internal reporter. +#[derive(Debug, Error)] +pub enum RecordReporterError { + /// An error occurred while writing to the run store. + #[error(transparent)] + RunStore(RunStoreError), +} + #[cfg(feature = "self-update")] mod self_update_errors { use super::*; diff --git a/nextest-runner/src/lib.rs b/nextest-runner/src/lib.rs index 72554adf570..258dbcde5cf 100644 --- a/nextest-runner/src/lib.rs +++ b/nextest-runner/src/lib.rs @@ -21,6 +21,7 @@ pub mod partition; pub mod platform; pub mod reporter; pub mod reuse_build; +pub mod run_store; pub mod runner; pub mod show_config; pub mod signal; diff --git a/nextest-runner/src/reporter.rs b/nextest-runner/src/reporter.rs index c7a8fe56951..b13defa5cc3 100644 --- a/nextest-runner/src/reporter.rs +++ b/nextest-runner/src/reporter.rs @@ -26,19 +26,20 @@ use debug_ignore::DebugIgnore; use indicatif::{ProgressBar, ProgressDrawTarget, ProgressStyle}; use nextest_metadata::MismatchReason; use owo_colors::{OwoColorize, Style}; -use serde::Deserialize; +use serde::{Deserialize, Serialize}; use std::{ borrow::Cow, cmp::Reverse, fmt::{self, Write as _}, io, io::{BufWriter, Write}, + sync::Arc, time::Duration, }; use uuid::Uuid; /// When to display test output in the reporter. -#[derive(Copy, Clone, Debug, Eq, PartialEq, Deserialize)] +#[derive(Copy, Clone, Debug, Eq, PartialEq, Deserialize, Serialize)] #[cfg_attr(test, derive(test_strategy::Arbitrary))] #[serde(rename_all = "kebab-case")] pub enum TestOutputDisplay { @@ -359,11 +360,29 @@ impl<'a> TestReporter<'a> { self.inner.styles.colorize(); } - /// Report a test event. + /// Reports test-related metadata. + /// + /// This is used by the structured reporter to emit metadata to the internal reporter, if + /// required. + pub fn report_meta(&mut self, cargo_metadata_json: &Arc, test_list: &TestList) { + self.structured_reporter + .write_meta(cargo_metadata_json, test_list); + } + + /// Reports a test event. pub fn report_event(&mut self, event: TestEvent<'a>) -> Result<(), WriteEventError> { self.write_event(event) } + /// Finishes writing events and flushes all internal caches. + /// + /// Must be called at the end of the test run. + pub fn finish(self) -> Result<(), WriteEventError> { + self.structured_reporter.finish()?; + // The metadata reporter doesn't have a finish method. + Ok(()) + } + // --- // Helper methods // --- @@ -400,7 +419,7 @@ impl<'a> TestReporter<'a> { } } - self.structured_reporter.write_event(&event)?; + self.structured_reporter.write_event(event.clone())?; self.metadata_reporter.write_event(event)?; Ok(()) } @@ -1890,8 +1909,9 @@ pub enum TestEventKind<'a> { // Note: the order here matters -- it indicates severity of cancellation /// The reason why a test run is being cancelled. -#[derive(Copy, Clone, Debug, Eq, PartialEq, Ord, PartialOrd)] +#[derive(Copy, Clone, Debug, Eq, PartialEq, Ord, PartialOrd, Serialize, Deserialize)] #[cfg_attr(test, derive(test_strategy::Arbitrary))] +#[serde(rename_all = "kebab-case")] pub enum CancelReason { /// A setup script failed. SetupScriptFailure, diff --git a/nextest-runner/src/reporter/structured.rs b/nextest-runner/src/reporter/structured.rs index 078f90d09d4..8229b9d61b3 100644 --- a/nextest-runner/src/reporter/structured.rs +++ b/nextest-runner/src/reporter/structured.rs @@ -2,9 +2,11 @@ //! formats mod libtest; +mod recorder; use super::*; pub use libtest::{EmitNextestObject, LibtestReporter}; +pub use recorder::RecordReporter; /// Error returned when a user-supplied format version fails to be parsed to a /// valid and supported version @@ -53,8 +55,8 @@ pub enum FormatVersionErrorInner { pub struct StructuredReporter<'a> { /// Libtest-compatible output written to stdout libtest: Option>, - // Internal structured reporter. - // internal: Option, + // Recorder for test events. + record: Option>, } impl<'a> StructuredReporter<'a> { @@ -64,15 +66,47 @@ impl<'a> StructuredReporter<'a> { } /// Sets libtest output for the `StructuredReporter`. + #[inline] pub fn set_libtest(&mut self, libtest: LibtestReporter<'a>) -> &mut Self { self.libtest = Some(libtest); self } + /// Sets recorder output for the `StructuredReporter`. + #[inline] + pub fn set_record(&mut self, record: RecordReporter<'a>) -> &mut Self { + self.record = Some(record); + self + } + #[inline] - pub(super) fn write_event(&mut self, event: &TestEvent<'a>) -> Result<(), WriteEventError> { + pub(super) fn write_meta( + &mut self, + cargo_metadata_json: &Arc, + test_list: &TestList<'_>, + ) { + if let Some(internal) = &mut self.record { + let cargo_metadata_json = cargo_metadata_json.clone(); + let test_list = test_list.to_summary(); + internal.write_meta(cargo_metadata_json, test_list); + } + } + + #[inline] + pub(super) fn write_event(&mut self, event: TestEvent<'a>) -> Result<(), WriteEventError> { if let Some(libtest) = &mut self.libtest { - libtest.write_event(event)?; + libtest.write_event(&event)?; + } + if let Some(record) = &mut self.record { + record.write_event(event); + } + Ok(()) + } + + #[inline] + pub(super) fn finish(self) -> Result<(), WriteEventError> { + if let Some(internal) = self.record { + internal.finish(); } Ok(()) } diff --git a/nextest-runner/src/reporter/structured/recorder.rs b/nextest-runner/src/reporter/structured/recorder.rs new file mode 100644 index 00000000000..158b3e1f68b --- /dev/null +++ b/nextest-runner/src/reporter/structured/recorder.rs @@ -0,0 +1,132 @@ +// Copyright (c) The nextest Contributors +// SPDX-License-Identifier: MIT OR Apache-2.0 + +//! Reporter for recording test runs. + +use super::TestEvent; +use crate::{ + errors::RecordReporterError, + run_store::{InMemoryOutput, RunRecorder, TestEventSummary}, +}; +use display_error_chain::DisplayErrorChain; +use nextest_metadata::TestListSummary; +use std::{ + sync::{mpsc, Arc}, + thread::JoinHandle, +}; + +/// A reporter used for recording test runs. +#[derive(Debug)] +pub struct RecordReporter<'a> { + // Invariant: sender is always Some while the reporter is alive. + sender: Option>, + handle: JoinHandle<()>, + _marker: std::marker::PhantomData<&'a ()>, +} + +impl<'a> RecordReporter<'a> { + /// Creates a new `RecordReporter`. + pub fn new(run_recorder: RunRecorder) -> Self { + // Spawn a thread to do the writing. + let (sender, receiver) = mpsc::sync_channel(128); + let handle = std::thread::spawn(move || { + let mut writer = RecordReporterWriter { run_recorder }; + while let Ok(event) = receiver.recv() { + if let Err(error) = writer.handle_event(event) { + log::error!( + "error recording run, will no longer store events: {}", + DisplayErrorChain::new(&error) + ); + return; + } + } + + // The sender has been dropped. Finish writing and exit. + if let Err(error) = writer.finish() { + log::error!( + "error finishing run recording: {}", + DisplayErrorChain::new(&error) + ); + } + }); + Self { + sender: Some(sender), + handle, + _marker: std::marker::PhantomData, + } + } + + /// Writes metadata to the internal reporter. + pub fn write_meta(&self, cargo_metadata_json: Arc, test_list: TestListSummary) { + let event = RecordEvent::Meta { + cargo_metadata_json, + test_list, + }; + // Ignore receive errors because they indicate that the receiver has exited (likely a + // panic, dealt with in finish()). + _ = self.sender.as_ref().unwrap().send(event); + } + + /// Writes a test event to the internal reporter. + pub fn write_event(&self, event: TestEvent<'_>) { + let event = RecordEvent::TestEvent(TestEventSummary::from_test_event(event)); + // Ignore receive errors because they indicate that the receiver has exited (likely a + // panic, dealt with in finish()). + _ = self.sender.as_ref().unwrap().send(event); + } + + /// Finishes writing to the internal reporter. + /// + /// This must be called before the reporter is dropped. + pub fn finish(mut self) { + // Drop the sender, which signals the receiver to exit. + let sender = self.sender.take(); + std::mem::drop(sender); + + // Wait for the thread to finish writing and exit. + match self.handle.join() { + Ok(()) => {} + Err(_) => { + panic!("writer thread panicked"); + } + } + } +} + +#[derive(Debug)] +struct RecordReporterWriter { + run_recorder: RunRecorder, +} + +impl RecordReporterWriter { + fn handle_event(&mut self, event: RecordEvent) -> Result<(), RecordReporterError> { + match event { + RecordEvent::Meta { + cargo_metadata_json, + test_list, + } => self + .run_recorder + .write_meta(&cargo_metadata_json, &test_list) + .map_err(RecordReporterError::RunStore), + RecordEvent::TestEvent(event) => self + .run_recorder + .write_event(event) + .map_err(RecordReporterError::RunStore), + } + } + + fn finish(self) -> Result<(), RecordReporterError> { + self.run_recorder + .finish() + .map_err(RecordReporterError::RunStore) + } +} + +#[derive(Debug)] +enum RecordEvent { + Meta { + cargo_metadata_json: Arc, + test_list: TestListSummary, + }, + TestEvent(TestEventSummary), +} diff --git a/nextest-runner/src/run_store.rs b/nextest-runner/src/run_store.rs new file mode 100644 index 00000000000..d96717f3407 --- /dev/null +++ b/nextest-runner/src/run_store.rs @@ -0,0 +1,1177 @@ +// Copyright (c) The nextest Contributors +// SPDX-License-Identifier: MIT OR Apache-2.0 + +//! Storage management for nextest runs. + +use crate::{ + config::ScriptId, + errors::{RunStoreError, StoreWriterError}, + list::TestInstance, + reporter::{CancelReason, TestEvent, TestEventKind, TestOutputDisplay}, + runner::{ + ExecuteStatus, ExecutionResult, ExecutionStatuses, RetryData, RunStats, + SetupScriptExecuteStatus, + }, + test_output::{TestOutput, TestSingleOutput}, +}; +use bytes::Bytes; +use camino::{Utf8Path, Utf8PathBuf}; +use chrono::{DateTime, FixedOffset}; +use debug_ignore::DebugIgnore; +use fs4::FileExt; +use nextest_metadata::{MismatchReason, RustBinaryId, RustTestCaseSummary, TestListSummary}; +use semver::Version; +use serde::{Deserialize, Serialize}; +use std::{ + collections::HashSet, + fmt, + fs::File, + io::{self, LineWriter, Write}, + time::Duration, +}; +use uuid::Uuid; +use xxhash_rust::xxh3::Xxh3; +use zip::ZipWriter; + +static RUNS_LOCK_FILE_NAME: &str = "runs.lock"; +static RUNS_JSON_FILE_NAME: &str = "runs.json"; +static STORE_ZIP_FILE_NAME: &str = "store.zip"; +static CARGO_METADATA_JSON_FILE_NAME: &str = "cargo-metadata.json"; +static TEST_LIST_JSON_FILE_NAME: &str = "test-list.json"; +static RUN_LOG_FILE_NAME: &str = "run.log"; + +/// Manages the storage of runs. +#[derive(Debug)] +pub struct RunStore { + runs_dir: Utf8PathBuf, +} + +impl RunStore { + /// Creates a new `RunStore`. + pub fn new(store_dir: &Utf8Path) -> Result { + let runs_dir = store_dir.join("runs"); + std::fs::create_dir_all(&runs_dir).map_err(|error| RunStoreError::RunDirCreate { + run_dir: runs_dir.clone(), + error, + })?; + + Ok(Self { runs_dir }) + } + + /// Acquires an exclusive lock on the run store. + /// + /// This lock should only be held for a short duration. + pub fn lock_exclusive(&self) -> Result, RunStoreError> { + let lock_file_path = self.runs_dir.join(RUNS_LOCK_FILE_NAME); + let file = std::fs::OpenOptions::new() + .create(true) + .write(true) + .open(&lock_file_path) + .map_err(|error| RunStoreError::FileLock { + path: lock_file_path.clone(), + error, + })?; + + // These locks are held for a small amount of time (just enough to add a run to the list of + // runs), so it's fine to block. + file.lock_exclusive() + .map_err(|error| RunStoreError::FileLock { + path: lock_file_path, + error, + })?; + + // Now that the file is locked, read the list of runs from disk and add to it. + let runs_json_path = self.runs_dir.join(RUNS_JSON_FILE_NAME); + let recorded_runs: RecordedRunList = match std::fs::read_to_string(&runs_json_path) { + Ok(runs_json) => serde_json::from_str(&runs_json).map_err(|error| { + RunStoreError::RunListDeserialize { + path: runs_json_path, + error, + } + })?, + Err(error) => { + // If the file doesn't exist, that's fine. We'll create it later. + if error.kind() == io::ErrorKind::NotFound { + RecordedRunList::default() + } else { + // TODO: we may want to delete and recreate this file if it's invalid. + return Err(RunStoreError::RunListRead { + path: runs_json_path.clone(), + error, + }); + } + } + }; + + Ok(ExclusiveLockedRunStore { + runs_dir: &self.runs_dir, + locked_file: DebugIgnore(file), + recorded_runs, + }) + } +} + +/// Represents a run store which has been locked for exclusive access. +/// +/// The lifetime parameter here is mostly to ensure that this isn't held for longer than the +/// corresponding [`RunStore`]. +#[derive(Debug)] +pub struct ExclusiveLockedRunStore<'store> { + runs_dir: &'store Utf8Path, + locked_file: DebugIgnore, + recorded_runs: RecordedRunList, +} + +impl<'store> ExclusiveLockedRunStore<'store> { + // TODO: prune old runs + + /// Creates a run in the run directory, adding it to the list of runs. + /// + /// Consumes self, dropping the exclusive lock on the run directory. + pub fn create_run_recorder( + mut self, + run_id: Uuid, + nextest_version: Version, + started_at: DateTime, + ) -> Result { + // Add to the list of runs before creating the directory. This ensures that if creation + // fails, an empty run directory isn't left behind. (It does mean that there may be spurious + // entries in the list of runs, which will be dealt with while doing pruning). + + let run = RecordedRun { + run_id, + nextest_version, + started_at, + }; + self.recorded_runs.runs.push(run); + + // Write to runs.json. + let runs_json_path = self.runs_dir.join(RUNS_JSON_FILE_NAME); + let runs_json = serde_json::to_string_pretty(&self.recorded_runs).map_err(|error| { + RunStoreError::RunListSerialize { + path: runs_json_path.clone(), + error, + } + })?; + + atomicwrites::AtomicFile::new(&runs_json_path, atomicwrites::AllowOverwrite) + .write(|file| file.write_all(runs_json.as_bytes())) + .map_err(|error| RunStoreError::RunListWrite { + path: runs_json_path, + error, + })?; + + // Drop the lock since we're done writing to runs.json. Errors here aren't important because + // the file will be closed soon anyway. + _ = self.locked_file.unlock(); + + // Now create the run directory. + let run_dir = self.runs_dir.join(run_id.to_string()); + + RunRecorder::new(run_dir) + } +} + +/// Manages the creation of a new run in the store. +#[derive(Debug)] +pub struct RunRecorder { + store_path: Utf8PathBuf, + store_writer: StoreWriter, + log_path: Utf8PathBuf, + log: DebugIgnore>, +} + +impl RunRecorder { + fn new(run_dir: Utf8PathBuf) -> Result { + std::fs::create_dir_all(&run_dir).map_err(|error| RunStoreError::RunDirCreate { + run_dir: run_dir.clone(), + error, + })?; + + let store_path = run_dir.join(STORE_ZIP_FILE_NAME); + let store_writer = + StoreWriter::new(&store_path).map_err(|error| RunStoreError::StoreWrite { + store_path: store_path.clone(), + error, + })?; + + let log_path = run_dir.join(RUN_LOG_FILE_NAME); + let file = std::fs::OpenOptions::new() + .create(true) + .write(true) + .open(&log_path) + .map_err(|error| RunStoreError::RunLogCreate { + path: log_path.clone(), + error, + })?; + + let log = LineWriter::new(file); + + Ok(Self { + store_path, + store_writer, + log_path, + log: DebugIgnore(log), + }) + } + + pub(crate) fn write_meta( + &mut self, + cargo_metadata_json: &str, + test_list: &TestListSummary, + ) -> Result<(), RunStoreError> { + let test_list_json = serde_json::to_string(test_list) + .map_err(|error| RunStoreError::TestListSerialize { error })?; + + self.write_meta_impl(TEST_LIST_JSON_FILE_NAME, test_list_json.as_bytes())?; + + self.write_meta_impl( + CARGO_METADATA_JSON_FILE_NAME, + cargo_metadata_json.as_bytes(), + )?; + + Ok(()) + } + + fn write_meta_impl(&mut self, file_name: &str, bytes: &[u8]) -> Result<(), RunStoreError> { + // Always use / while joining paths in the zip. + let path = Utf8PathBuf::from(format!("meta/{file_name}")); + self.store_writer + .add_file(path, bytes) + .map_err(|error| RunStoreError::StoreWrite { + store_path: self.store_path.clone(), + error, + }) + } + + pub(crate) fn write_event( + &mut self, + event: TestEventSummary, + ) -> Result<(), RunStoreError> { + let mut cx = SerializeTestEventSummaryContext { + store_writer: &mut self.store_writer, + }; + + let event = cx + .handle_test_event(event) + .map_err(|error| RunStoreError::StoreWrite { + store_path: self.store_path.clone(), + error, + })?; + + let json = serde_json::to_string(&event) + .map_err(|error| RunStoreError::TestEventSerialize { error })?; + self.write_log_impl(json.as_bytes())?; + self.write_log_impl(b"\n")?; + + Ok(()) + } + + fn write_log_impl(&mut self, bytes: &[u8]) -> Result<(), RunStoreError> { + self.log + .write_all(bytes) + .map_err(|error| RunStoreError::RunLogWrite { + path: self.log_path.clone(), + error, + }) + } + + pub(crate) fn finish(mut self) -> Result<(), RunStoreError> { + // Close and flush the log file. + self.log + .flush() + .map_err(|error| RunStoreError::RunLogFlush { + path: self.log_path.clone(), + error, + })?; + + // Also finish the store file. + self.store_writer + .finish() + .map_err(|error| RunStoreError::StoreWrite { + store_path: self.store_path.clone(), + error, + })?; + + Ok(()) + } +} + +#[derive(Debug)] +struct StoreWriter { + writer: DebugIgnore>, + added_files: HashSet, +} + +impl StoreWriter { + fn new(store_path: &Utf8Path) -> Result { + let zip_file = std::fs::OpenOptions::new() + .create(true) + .write(true) + .open(store_path) + .map_err(|error| StoreWriterError::Create { error })?; + let writer = ZipWriter::new(zip_file); + + Ok(Self { + writer: DebugIgnore(writer), + added_files: HashSet::new(), + }) + } + + fn add_file(&mut self, path: Utf8PathBuf, contents: &[u8]) -> Result<(), StoreWriterError> { + if self.added_files.contains(&path) { + // The file has already been added to the store. + return Ok(()); + } + + let options = + zip::write::FileOptions::default().compression_method(zip::CompressionMethod::Zstd); + self.writer + .start_file(path.clone(), options) + .map_err(|error| StoreWriterError::StartFile { + path: path.clone(), + error, + })?; + + self.writer + .write_all(contents) + .map_err(|error| StoreWriterError::Write { + path: path.clone(), + error, + })?; + + self.added_files.insert(path); + + Ok(()) + } + + fn finish(mut self) -> Result<(), StoreWriterError> { + let mut writer = self + .writer + .finish() + .map_err(|error| StoreWriterError::Finish { error })?; + + writer + .flush() + .map_err(|error| StoreWriterError::Flush { error })?; + + Ok(()) + } +} + +#[derive(Debug, Default, Deserialize, Serialize)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct RecordedRunList { + #[serde(default)] + pub(crate) runs: Vec, +} + +#[derive(Debug, Deserialize, Serialize)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct RecordedRun { + pub(crate) run_id: Uuid, + pub(crate) nextest_version: Version, + pub(crate) started_at: DateTime, +} + +/// Context to create a [`TestEventSummary`] out of a +/// [`TestEventSummary`]. +#[derive(Debug)] +struct SerializeTestEventSummaryContext<'a> { + store_writer: &'a mut StoreWriter, +} + +impl<'a> SerializeTestEventSummaryContext<'a> { + fn handle_test_event( + &mut self, + event: TestEventSummary, + ) -> Result, StoreWriterError> { + Ok(TestEventSummary { + timestamp: event.timestamp, + elapsed: event.elapsed, + kind: self.handle_test_event_kind(event.kind)?, + }) + } + + fn handle_test_event_kind( + &mut self, + kind: TestEventKindSummary, + ) -> Result, StoreWriterError> { + match kind { + TestEventKindSummary::RunStarted { + run_id, + profile_name, + cli_args, + } => Ok(TestEventKindSummary::RunStarted { + run_id, + profile_name, + cli_args, + }), + TestEventKindSummary::SetupScriptStarted { + index, + total, + script_id, + command, + args, + no_capture, + } => Ok(TestEventKindSummary::SetupScriptStarted { + index, + total, + script_id, + command: command.to_string(), + args: args.to_vec(), + no_capture, + }), + TestEventKindSummary::SetupScriptSlow { + script_id, + command, + args, + elapsed, + will_terminate, + } => Ok(TestEventKindSummary::SetupScriptSlow { + script_id, + command: command.to_string(), + args: args.to_vec(), + elapsed, + will_terminate, + }), + TestEventKindSummary::SetupScriptFinished { + index, + total, + script_id, + command, + args, + no_capture, + run_status, + } => { + let run_status = + self.handle_setup_script_execute_status(&run_status, &script_id)?; + Ok(TestEventKindSummary::SetupScriptFinished { + index, + total, + script_id, + command: command.to_string(), + args: args.to_vec(), + no_capture, + run_status, + }) + } + TestEventKindSummary::TestStarted { + test_instance, + current_stats, + running, + cancel_state, + } => Ok(TestEventKindSummary::TestStarted { + test_instance, + current_stats, + running, + cancel_state, + }), + TestEventKindSummary::TestSlow { + test_instance, + retry_data, + elapsed, + will_terminate, + } => Ok(TestEventKindSummary::TestSlow { + test_instance, + retry_data, + elapsed, + will_terminate, + }), + TestEventKindSummary::TestAttemptFailedWillRetry { + test_instance, + run_status, + delay_before_next_attempt, + failure_output, + } => { + let run_status = self.handle_execute_status(run_status, &test_instance)?; + Ok(TestEventKindSummary::TestAttemptFailedWillRetry { + test_instance, + run_status, + delay_before_next_attempt, + failure_output, + }) + } + TestEventKindSummary::TestRetryStarted { + test_instance, + retry_data, + } => Ok(TestEventKindSummary::TestRetryStarted { + test_instance, + retry_data, + }), + TestEventKindSummary::TestFinished { + test_instance, + success_output, + failure_output, + junit_store_success_output, + junit_store_failure_output, + run_statuses, + current_stats, + running, + cancel_state, + } => { + let run_statuses = self.handle_execution_statuses(run_statuses, &test_instance)?; + Ok(TestEventKindSummary::TestFinished { + test_instance, + success_output, + failure_output, + junit_store_success_output, + junit_store_failure_output, + run_statuses, + current_stats, + running, + cancel_state, + }) + } + TestEventKindSummary::TestSkipped { + test_instance, + reason, + } => Ok(TestEventKindSummary::TestSkipped { + test_instance, + reason, + }), + TestEventKindSummary::RunBeginCancel { + setup_scripts_running, + running, + reason, + } => Ok(TestEventKindSummary::RunBeginCancel { + setup_scripts_running, + running, + reason, + }), + TestEventKindSummary::RunPaused { + setup_scripts_running, + running, + } => Ok(TestEventKindSummary::RunPaused { + setup_scripts_running, + running, + }), + TestEventKindSummary::RunContinued { + setup_scripts_running, + running, + } => Ok(TestEventKindSummary::RunContinued { + setup_scripts_running, + running, + }), + TestEventKindSummary::RunFinished { + run_id, + start_time, + elapsed, + run_stats, + } => Ok(TestEventKindSummary::RunFinished { + run_id, + start_time, + elapsed, + run_stats, + }), + } + } + + fn handle_setup_script_execute_status( + &mut self, + status: &SetupScriptExecuteStatusSummary, + script_id: &ScriptId, + ) -> Result, StoreWriterError> { + let digest: String = script_id.to_hex_digest(); + let prefix = format!("script-{digest}"); + Ok(SetupScriptExecuteStatusSummary { + stdout: self.handle_test_single_output( + &status.stdout, + &prefix, + TestSingleOutputKind::Stdout, + )?, + stderr: self.handle_test_single_output( + &status.stderr, + &prefix, + TestSingleOutputKind::Stderr, + )?, + result: status.result, + start_time: status.start_time, + time_taken: status.time_taken, + is_slow: status.is_slow, + env_count: status.env_count, + }) + } + + fn handle_execution_statuses( + &mut self, + statuses: ExecutionStatusesSummary, + test_instance: &TestInstanceSummary, + ) -> Result, StoreWriterError> { + let statuses = statuses + .statuses + .into_iter() + .map(|status| self.handle_execute_status(status, test_instance)) + .collect::, _>>()?; + Ok(ExecutionStatusesSummary { statuses }) + } + + fn handle_execute_status( + &mut self, + status: ExecuteStatusSummary, + test_instance: &TestInstanceSummary, + ) -> Result, StoreWriterError> { + let hex_digest = test_instance.to_hex_digest(); + let prefix = format!("test-{hex_digest}-{}", status.retry_data.attempt); + + // The output should only be persisted if the corresponding file doesn't actually exist + // already. + let output = status + .output + .map(|output| self.handle_test_output(output, &prefix)) + .transpose()?; + + Ok(ExecuteStatusSummary { + retry_data: status.retry_data, + output, + result: status.result, + start_time: status.start_time, + time_taken: status.time_taken, + is_slow: status.is_slow, + delay_before_start: status.delay_before_start, + }) + } + + fn handle_test_output( + &mut self, + output: TestOutputSummary, + prefix: &str, + ) -> Result, StoreWriterError> { + match output { + TestOutputSummary::Split { stdout, stderr } => Ok(TestOutputSummary::Split { + stdout: self.handle_test_single_output( + &stdout, + prefix, + TestSingleOutputKind::Stdout, + )?, + stderr: self.handle_test_single_output( + &stderr, + prefix, + TestSingleOutputKind::Stderr, + )?, + }), + TestOutputSummary::Combined { output } => Ok(TestOutputSummary::Combined { + output: self.handle_test_single_output( + &output, + prefix, + TestSingleOutputKind::Combined, + )?, + }), + TestOutputSummary::ExecFail { + message, + description, + } => Ok(TestOutputSummary::ExecFail { + message, + description, + }), + } + } + + fn handle_test_single_output( + &mut self, + output: &InMemoryOutput, + prefix: &str, + kind: TestSingleOutputKind, + ) -> Result { + // Write the output to a file, if it is non-empty. + let file_name = if !output.buf.is_empty() { + // Always use / while joining paths in the zip. + let file_name = format!("{prefix}-{kind}"); + let file_path = Utf8PathBuf::from(format!("out/{file_name}")); + self.store_writer.add_file(file_path, &output.buf)?; + + Some(file_name) + } else { + None + }; + + Ok(ZipStoreOutput { file_name }) + } +} + +/// A serializable form of a test event. +/// +/// Someday this will be stabilized and move to `nextest-metadata`. +/// +/// The `O` parameter represents the way test outputs (stdout/stderr) have been stored. +/// +/// * First, a `TestEvent` is transformed to one where the output is stored in-memory +/// (`InMemoryOutput`). (This is required because TestEvent isn't 'static and events must be sent +/// across threads.) +/// * Then, the output is stored in the store.zip file. This is represented by `ZipStoreOutput`. +#[derive(Deserialize, Serialize, Debug)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct TestEventSummary { + /// The timestamp of the event. + pub timestamp: DateTime, + + /// The time elapsed since the start of the test run. + pub elapsed: Duration, + + /// The kind of test event this is. + pub kind: TestEventKindSummary, +} + +impl TestEventSummary { + pub(crate) fn from_test_event(event: TestEvent<'_>) -> Self { + Self { + timestamp: event.timestamp, + elapsed: event.elapsed, + kind: TestEventKindSummary::from_test_event_kind(event.kind), + } + } +} + +#[derive(Deserialize, Serialize, Debug)] +#[serde(tag = "kind", rename_all = "kebab-case")] +pub(crate) enum TestEventKindSummary { + #[serde(rename_all = "kebab-case")] + RunStarted { + run_id: Uuid, + profile_name: String, + cli_args: Vec, + }, + #[serde(rename_all = "kebab-case")] + SetupScriptStarted { + index: usize, + total: usize, + script_id: ScriptId, + command: String, + args: Vec, + no_capture: bool, + }, + #[serde(rename_all = "kebab-case")] + SetupScriptSlow { + script_id: ScriptId, + command: String, + args: Vec, + elapsed: Duration, + will_terminate: bool, + }, + #[serde(rename_all = "kebab-case")] + SetupScriptFinished { + index: usize, + total: usize, + script_id: ScriptId, + command: String, + args: Vec, + no_capture: bool, + run_status: SetupScriptExecuteStatusSummary, + }, + #[serde(rename_all = "kebab-case")] + TestStarted { + test_instance: TestInstanceSummary, + current_stats: RunStats, + running: usize, + cancel_state: Option, + }, + #[serde(rename_all = "kebab-case")] + TestSlow { + test_instance: TestInstanceSummary, + retry_data: RetryData, + elapsed: Duration, + will_terminate: bool, + }, + #[serde(rename_all = "kebab-case")] + TestAttemptFailedWillRetry { + test_instance: TestInstanceSummary, + run_status: ExecuteStatusSummary, + delay_before_next_attempt: Duration, + failure_output: TestOutputDisplay, + }, + #[serde(rename_all = "kebab-case")] + TestRetryStarted { + test_instance: TestInstanceSummary, + retry_data: RetryData, + }, + #[serde(rename_all = "kebab-case")] + TestFinished { + test_instance: TestInstanceSummary, + success_output: TestOutputDisplay, + failure_output: TestOutputDisplay, + junit_store_success_output: bool, + junit_store_failure_output: bool, + run_statuses: ExecutionStatusesSummary, + current_stats: RunStats, + running: usize, + cancel_state: Option, + }, + #[serde(rename_all = "kebab-case")] + TestSkipped { + test_instance: TestInstanceSummary, + reason: MismatchReason, + }, + #[serde(rename_all = "kebab-case")] + RunBeginCancel { + setup_scripts_running: usize, + running: usize, + reason: CancelReason, + }, + #[serde(rename_all = "kebab-case")] + RunPaused { + setup_scripts_running: usize, + running: usize, + }, + #[serde(rename_all = "kebab-case")] + RunContinued { + setup_scripts_running: usize, + running: usize, + }, + #[serde(rename_all = "kebab-case")] + RunFinished { + run_id: Uuid, + start_time: DateTime, + elapsed: Duration, + run_stats: RunStats, + }, +} + +impl TestEventKindSummary { + fn from_test_event_kind(kind: TestEventKind<'_>) -> Self { + match kind { + TestEventKind::RunStarted { + run_id, + test_list: _, + profile_name, + cli_args, + } => Self::RunStarted { + run_id, + profile_name, + cli_args, + }, + TestEventKind::SetupScriptStarted { + index, + total, + script_id, + command, + args, + no_capture, + } => Self::SetupScriptStarted { + index, + total, + script_id, + command: command.to_string(), + args: args.to_vec(), + no_capture, + }, + TestEventKind::SetupScriptSlow { + script_id, + command, + args, + elapsed, + will_terminate, + } => Self::SetupScriptSlow { + script_id, + command: command.to_string(), + args: args.to_vec(), + elapsed, + will_terminate, + }, + TestEventKind::SetupScriptFinished { + index, + total, + script_id, + command, + args, + no_capture, + run_status, + } => Self::SetupScriptFinished { + index, + total, + script_id, + command: command.to_string(), + args: args.to_vec(), + no_capture, + run_status: SetupScriptExecuteStatusSummary::from_setup_script_execute_status( + run_status, + ), + }, + TestEventKind::TestStarted { + test_instance, + current_stats, + running, + cancel_state, + } => Self::TestStarted { + test_instance: TestInstanceSummary::from_test_instance(test_instance), + current_stats, + running, + cancel_state, + }, + TestEventKind::TestSlow { + test_instance, + retry_data, + elapsed, + will_terminate, + } => Self::TestSlow { + test_instance: TestInstanceSummary::from_test_instance(test_instance), + retry_data, + elapsed, + will_terminate, + }, + TestEventKind::TestAttemptFailedWillRetry { + test_instance, + run_status, + delay_before_next_attempt, + failure_output, + } => Self::TestAttemptFailedWillRetry { + test_instance: TestInstanceSummary::from_test_instance(test_instance), + run_status: ExecuteStatusSummary::from_execute_status(run_status), + delay_before_next_attempt, + failure_output, + }, + TestEventKind::TestRetryStarted { + test_instance, + retry_data, + } => Self::TestRetryStarted { + test_instance: TestInstanceSummary::from_test_instance(test_instance), + retry_data, + }, + TestEventKind::TestFinished { + test_instance, + success_output, + failure_output, + junit_store_success_output, + junit_store_failure_output, + run_statuses, + current_stats, + running, + cancel_state, + } => { + let run_statuses = ExecutionStatusesSummary::from_execution_statuses(run_statuses); + Self::TestFinished { + test_instance: TestInstanceSummary::from_test_instance(test_instance), + success_output, + failure_output, + junit_store_success_output, + junit_store_failure_output, + run_statuses, + current_stats, + running, + cancel_state, + } + } + TestEventKind::TestSkipped { + test_instance, + reason, + } => Self::TestSkipped { + test_instance: TestInstanceSummary::from_test_instance(test_instance), + reason, + }, + TestEventKind::RunBeginCancel { + setup_scripts_running, + running, + reason, + } => Self::RunBeginCancel { + setup_scripts_running, + running, + reason, + }, + TestEventKind::RunPaused { + setup_scripts_running, + running, + } => Self::RunPaused { + setup_scripts_running, + running, + }, + TestEventKind::RunContinued { + setup_scripts_running, + running, + } => Self::RunContinued { + setup_scripts_running, + running, + }, + TestEventKind::RunFinished { + run_id, + start_time, + elapsed, + run_stats, + } => Self::RunFinished { + run_id, + start_time, + elapsed, + run_stats, + }, + } + } +} + +#[derive(Deserialize, Serialize, Debug)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct SetupScriptExecuteStatusSummary { + stdout: O, + stderr: O, + result: ExecutionResult, + start_time: DateTime, + time_taken: Duration, + is_slow: bool, + // TODO: store env vars here + env_count: usize, +} + +impl SetupScriptExecuteStatusSummary { + fn from_setup_script_execute_status(status: SetupScriptExecuteStatus) -> Self { + Self { + stdout: InMemoryOutput::from_test_single_output(status.stdout), + stderr: InMemoryOutput::from_test_single_output(status.stderr), + result: status.result, + start_time: status.start_time, + time_taken: status.time_taken, + is_slow: status.is_slow, + env_count: status.env_count, + } + } +} + +#[derive(Serialize, Debug)] +pub(crate) struct ExecutionStatusesSummary { + /// This is guaranteed to be non-empty. + statuses: Vec>, +} + +impl<'de, O: Deserialize<'de>> Deserialize<'de> for ExecutionStatusesSummary { + fn deserialize>(deserializer: D) -> Result { + let statuses = Vec::>::deserialize(deserializer)?; + if statuses.is_empty() { + return Err(serde::de::Error::custom("expected non-empty statuses")); + } + Ok(Self { statuses }) + } +} + +impl ExecutionStatusesSummary { + fn from_execution_statuses(statuses: ExecutionStatuses) -> Self { + Self { + statuses: statuses + .statuses + .into_iter() + .map(ExecuteStatusSummary::from_execute_status) + .collect(), + } + } +} + +#[derive(Deserialize, Serialize, Debug)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct ExecuteStatusSummary { + retry_data: RetryData, + output: Option>, + result: ExecutionResult, + start_time: DateTime, + time_taken: Duration, + is_slow: bool, + delay_before_start: Duration, +} + +impl ExecuteStatusSummary { + fn from_execute_status(status: ExecuteStatus) -> Self { + let output = status.output.map(TestOutputSummary::from_test_output); + Self { + retry_data: status.retry_data, + output, + result: status.result, + start_time: status.start_time, + time_taken: status.time_taken, + is_slow: status.is_slow, + delay_before_start: status.delay_before_start, + } + } +} + +#[derive(Deserialize, Serialize, Debug)] +#[serde(tag = "kind", rename_all = "kebab-case")] +pub(crate) enum TestOutputSummary { + #[serde(rename_all = "kebab-case")] + Split { stdout: O, stderr: O }, + #[serde(rename_all = "kebab-case")] + Combined { output: O }, + #[serde(rename_all = "kebab-case")] + ExecFail { + message: String, + description: String, + }, +} + +impl TestOutputSummary { + fn from_test_output(output: TestOutput) -> Self { + match output { + TestOutput::Split { stdout, stderr } => Self::Split { + stdout: InMemoryOutput::from_test_single_output(stdout), + stderr: InMemoryOutput::from_test_single_output(stderr), + }, + TestOutput::Combined { output } => Self::Combined { + output: InMemoryOutput::from_test_single_output(output), + }, + TestOutput::ExecFail { + message, + description, + } => Self::ExecFail { + message, + description, + }, + } + } +} + +#[derive(Debug)] +pub(crate) struct InMemoryOutput { + buf: Bytes, +} + +impl InMemoryOutput { + fn from_test_single_output(output: TestSingleOutput) -> Self { + Self { buf: output.buf } + } +} + +#[derive(Deserialize, Serialize, Debug)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct ZipStoreOutput { + file_name: Option, +} + +#[derive(Clone, Copy, Debug)] +enum TestSingleOutputKind { + Stdout, + Stderr, + Combined, +} + +impl fmt::Display for TestSingleOutputKind { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + match self { + Self::Stdout => write!(f, "stdout"), + Self::Stderr => write!(f, "stderr"), + Self::Combined => write!(f, "combined"), + } + } +} + +/// Information about a test instance. +#[derive(Deserialize, Serialize, Debug)] +#[serde(rename_all = "kebab-case")] +pub(crate) struct TestInstanceSummary { + binary_id: RustBinaryId, + name: String, + info: RustTestCaseSummary, +} + +impl TestInstanceSummary { + fn from_test_instance(instance: TestInstance<'_>) -> Self { + Self { + binary_id: instance.suite_info.binary_id.clone(), + name: instance.name.to_string(), + info: instance.test_info.clone(), + } + } + + fn to_hex_digest(&self) -> String { + // Hash the test instance name. + let mut hasher = Xxh3::new(); + hasher.update(self.binary_id.as_str().as_bytes()); + hasher.update(b"\0"); + hasher.update(self.name.as_bytes()); + let digest = hasher.digest(); + // Pad to 16 hex digits (64 bits). + format!("{:016x}", digest) + } +} diff --git a/nextest-runner/src/runner.rs b/nextest-runner/src/runner.rs index 6cece2b8216..503f922b076 100644 --- a/nextest-runner/src/runner.rs +++ b/nextest-runner/src/runner.rs @@ -26,12 +26,13 @@ use crate::{ }; use async_scoped::TokioScope; use bytes::{Bytes, BytesMut}; -use chrono::{DateTime, FixedOffset}; +use chrono::{DateTime, FixedOffset, Local}; use display_error_chain::DisplayErrorChain; use future_queue::StreamExt; use futures::{future::try_join, prelude::*}; use nextest_metadata::{FilterMatch, MismatchReason}; use rand::{distributions::OpenClosed01, thread_rng, Rng}; +use serde::{Deserialize, Serialize}; use std::{ convert::Infallible, fmt::Write, @@ -203,6 +204,7 @@ impl TestRunnerBuilder { target_runner, runtime, run_id: Uuid::new_v4(), + stopwatch: crate::time::stopwatch(), }, handler, }) @@ -219,6 +221,16 @@ pub struct TestRunner<'a> { } impl<'a> TestRunner<'a> { + /// Returns a UUID for the run. + pub fn run_id(&self) -> Uuid { + self.inner.run_id + } + + /// Returns the time at which the run was started. + pub fn started_at(&self) -> DateTime { + self.inner.stopwatch.start_time() + } + /// Executes the listed tests, each one in its own process. /// /// The callback is called with the results of each test. @@ -265,6 +277,7 @@ struct TestRunnerInner<'a> { target_runner: TargetRunner, runtime: Runtime, run_id: Uuid, + stopwatch: StopwatchStart, } impl<'a> TestRunnerInner<'a> { @@ -290,6 +303,7 @@ impl<'a> TestRunnerInner<'a> { self.run_id, self.profile.name(), self.cli_args.clone(), + self.stopwatch.clone(), self.test_list.run_count(), self.fail_fast, ); @@ -1235,7 +1249,8 @@ async fn read_all_to_bytes( } /// Data related to retries. -#[derive(Clone, Copy, Debug, Eq, PartialEq, PartialOrd, Ord)] +#[derive(Clone, Copy, Debug, Eq, PartialEq, PartialOrd, Ord, Deserialize, Serialize)] +#[serde(rename_all = "kebab-case")] pub struct RetryData { /// The current attempt. In the range `[1, total_attempts]`. pub attempt: usize, @@ -1255,7 +1270,7 @@ impl RetryData { #[derive(Clone, Debug)] pub struct ExecutionStatuses { /// This is guaranteed to be non-empty. - statuses: Vec, + pub(crate) statuses: Vec, } #[allow(clippy::len_without_is_empty)] // RunStatuses is never empty @@ -1482,7 +1497,8 @@ impl InternalSetupScriptExecuteStatus { } /// Statistics for a test run. -#[derive(Copy, Clone, Default, Debug, Eq, PartialEq)] +#[derive(Copy, Clone, Default, Debug, Eq, PartialEq, Serialize, Deserialize)] +#[serde(rename_all = "kebab-case")] pub struct RunStats { /// The total number of tests that were expected to be run at the beginning. /// @@ -1705,15 +1721,16 @@ where run_id: Uuid, profile_name: &str, cli_args: Vec, + stopwatch: StopwatchStart, initial_run_count: usize, fail_fast: bool, ) -> Self { Self { callback, run_id, - stopwatch: crate::time::stopwatch(), profile_name: profile_name.to_owned(), cli_args, + stopwatch, run_stats: RunStats { initial_run_count, ..RunStats::default() @@ -2056,7 +2073,8 @@ enum InternalError { } /// Whether a test passed, failed or an error occurred while executing the test. -#[derive(Copy, Clone, Debug, Eq, PartialEq)] +#[derive(Copy, Clone, Debug, Eq, PartialEq, Serialize, Deserialize)] +#[serde(tag = "result", rename_all = "kebab-case")] pub enum ExecutionResult { /// The test passed. Pass, @@ -2067,6 +2085,7 @@ pub enum ExecutionResult { /// This is treated as a pass. Leak, /// The test failed. + #[serde(rename_all = "kebab-case")] Fail { /// The abort status of the test, if any (for example, the signal on Unix). abort_status: Option, @@ -2097,7 +2116,8 @@ impl ExecutionResult { /// A regular exit code or Windows NT abort status for a test. /// /// Returned as part of the [`ExecutionResult::Fail`] variant. -#[derive(Copy, Clone, Debug, Eq, PartialEq)] +#[derive(Copy, Clone, Debug, Eq, PartialEq, Serialize, Deserialize)] +#[serde(tag = "kind")] pub enum AbortStatus { /// The test was aborted due to a signal on Unix. #[cfg(unix)] diff --git a/nextest-runner/src/time/stopwatch.rs b/nextest-runner/src/time/stopwatch.rs index 2c8a7d8b2a7..36216b7a58c 100644 --- a/nextest-runner/src/time/stopwatch.rs +++ b/nextest-runner/src/time/stopwatch.rs @@ -35,6 +35,10 @@ impl StopwatchStart { } } + pub(crate) fn start_time(&self) -> DateTime { + self.start_time + } + pub(crate) fn is_paused(&self) -> bool { matches!(self.pause_state, StopwatchPauseState::Paused { .. }) } diff --git a/workspace-hack/Cargo.toml b/workspace-hack/Cargo.toml index bf5e30a2edb..d552b3ab98e 100644 --- a/workspace-hack/Cargo.toml +++ b/workspace-hack/Cargo.toml @@ -15,7 +15,7 @@ publish = false ### BEGIN HAKARI SECTION [dependencies] backtrace = { version = "0.3.69", features = ["gimli-symbolize"] } -chrono = { version = "0.4.33" } +chrono = { version = "0.4.33", features = ["serde"] } clap = { version = "4.4.18", features = ["derive", "env"] } clap_builder = { version = "4.4.18", default-features = false, features = ["color", "env", "help", "std", "suggestions", "usage"] } console = { version = "0.15.7" } @@ -34,7 +34,7 @@ serde = { version = "1.0.196", features = ["alloc", "derive"] } serde_json = { version = "1.0.113", features = ["preserve_order", "unbounded_depth"] } similar = { version = "2.3.0", features = ["inline", "unicode"] } tokio = { version = "1.35.1", features = ["fs", "io-util", "macros", "process", "rt-multi-thread", "signal", "sync", "time", "tracing"] } -uuid = { version = "1.7.0", features = ["v4"] } +uuid = { version = "1.7.0", features = ["serde", "v4"] } xxhash-rust = { version = "0.8.8", default-features = false, features = ["xxh3", "xxh64"] } [build-dependencies]