diff --git a/.ignore b/.ignore index f10e171d317..e51dabef3e8 100644 --- a/.ignore +++ b/.ignore @@ -12,4 +12,8 @@ src/etc/man !src/doc/src/commands/index.md !src/doc/src/commands/manifest-commands.md !src/doc/src/commands/package-commands.md -!src/doc/src/commands/publishg-commands.md +!src/doc/src/commands/publishing-commands.md + +# Snapshots of HTML reports and log files are just too large +tests/testsuite/**/*.jsonl +tests/testsuite/**/*.html diff --git a/crates/cargo-test-support/src/paths.rs b/crates/cargo-test-support/src/paths.rs index c6d91c1bd52..a7400380ee5 100644 --- a/crates/cargo-test-support/src/paths.rs +++ b/crates/cargo-test-support/src/paths.rs @@ -119,6 +119,41 @@ pub fn cargo_home() -> PathBuf { home().join(".cargo") } +/// Path to the current test's `$CARGO_LOG` +/// +/// ex: `$CARGO_TARGET_TMPDIR/cit/t0/home/.cargo/log` +pub fn log_dir() -> PathBuf { + cargo_home().join("log") +} + +/// Path to the current test's `$CARGO_LOG` file +/// +/// ex: `$CARGO_TARGET_TMPDIR/cit/t0/home/.cargo/log/.jsonl` +/// +/// This also asserts the number of log files is exactly the same as `idx + 1`. +pub fn log_file(idx: usize) -> PathBuf { + let log_dir = log_dir(); + + let entries = std::fs::read_dir(&log_dir).unwrap(); + let mut log_files: Vec<_> = entries + .filter_map(Result::ok) + .filter(|e| e.path().extension().and_then(|s| s.to_str()) == Some("jsonl")) + .collect(); + + // Sort them to get chronological order + log_files.sort_unstable_by(|a, b| a.file_name().to_str().cmp(&b.file_name().to_str())); + + assert_eq!( + idx + 1, + log_files.len(), + "unexpected number of log files: {}, expected {}", + log_files.len(), + idx + 1 + ); + + log_files[idx].path() +} + /// Common path and file operations pub trait CargoPathExt { fn to_url(&self) -> url::Url; diff --git a/src/bin/cargo/commands/report.rs b/src/bin/cargo/commands/report.rs index 6283d490203..f2dda0d28c0 100644 --- a/src/bin/cargo/commands/report.rs +++ b/src/bin/cargo/commands/report.rs @@ -1,6 +1,10 @@ use crate::command_prelude::*; -use cargo::core::compiler::future_incompat::{OnDiskReports, REPORT_PREAMBLE}; + +use cargo::CargoResult; +use cargo::core::compiler::future_incompat::OnDiskReports; +use cargo::core::compiler::future_incompat::REPORT_PREAMBLE; use cargo::drop_println; +use cargo::ops; pub fn cli() -> Command { subcommand("report") @@ -23,11 +27,28 @@ pub fn cli() -> Command { ) .arg_package("Package to display a report for"), ) + .subcommand( + subcommand("timings") + .about("Reports the build timings of previous builds (unstable)") + .arg(flag("open", "Opens the timing report in a browser")), + ) } pub fn exec(gctx: &mut GlobalContext, args: &ArgMatches) -> CliResult { match args.subcommand() { Some(("future-incompatibilities", args)) => report_future_incompatibilities(gctx, args), + Some(("timings", args)) => { + gctx.cli_unstable().fail_if_stable_command( + gctx, + "report timings", + 15844, + "build-analysis", + gctx.cli_unstable().build_analysis, + )?; + let opts = timings_opts(gctx, args)?; + ops::report_timings(gctx, opts)?; + Ok(()) + } Some((cmd, _)) => { unreachable!("unexpected command {}", cmd) } @@ -49,3 +70,12 @@ fn report_future_incompatibilities(gctx: &GlobalContext, args: &ArgMatches) -> C drop(gctx.shell().print_ansi_stdout(report.as_bytes())); Ok(()) } + +fn timings_opts<'a>( + gctx: &'a GlobalContext, + args: &ArgMatches, +) -> CargoResult> { + let open_result = args.get_flag("open"); + + Ok(ops::ReportTimingsOptions { open_result, gctx }) +} diff --git a/src/cargo/ops/cargo_doc.rs b/src/cargo/ops/cargo_doc.rs index 36c34e94aab..b8975a3a9a4 100644 --- a/src/cargo/ops/cargo_doc.rs +++ b/src/cargo/ops/cargo_doc.rs @@ -1,17 +1,15 @@ +use crate::core::Workspace; use crate::core::compiler::{Compilation, CompileKind}; -use crate::core::{Shell, Workspace, shell::Verbosity}; +use crate::core::shell::Verbosity; use crate::ops; use crate::util; use crate::util::CargoResult; -use crate::util::context::{GlobalContext, PathAndArgs}; use anyhow::{Error, bail}; use cargo_util::ProcessBuilder; use std::ffi::OsString; -use std::path::Path; use std::path::PathBuf; -use std::process::Command; use std::str::FromStr; /// Format of rustdoc [`--output-format`][1]. @@ -75,14 +73,7 @@ pub fn doc(ws: &Workspace<'_>, options: &DocOptions) -> CargoResult<()> { let path = path_by_output_format(&compilation, &kind, &name, &options.output_format); if path.exists() { - let config_browser = { - let cfg: Option = ws.gctx().get("doc.browser")?; - cfg.map(|path_args| (path_args.path.resolve_program(ws.gctx()), path_args.args)) - }; - let mut shell = ws.gctx().shell(); - let link = shell.err_file_hyperlink(&path); - shell.status("Opening", format!("{link}{}{link:#}", path.display()))?; - open_docs(&path, &mut shell, config_browser, ws.gctx())?; + util::open::open(&path, ws.gctx())?; } } else if ws.gctx().shell().verbosity() == Verbosity::Verbose { for name in &compilation.root_crate_names { @@ -216,33 +207,3 @@ fn path_by_output_format( .join("index.html") } } - -fn open_docs( - path: &Path, - shell: &mut Shell, - config_browser: Option<(PathBuf, Vec)>, - gctx: &GlobalContext, -) -> CargoResult<()> { - let browser = - config_browser.or_else(|| Some((PathBuf::from(gctx.get_env_os("BROWSER")?), Vec::new()))); - - match browser { - Some((browser, initial_args)) => { - if let Err(e) = Command::new(&browser).args(initial_args).arg(path).status() { - shell.warn(format!( - "Couldn't open docs with {}: {}", - browser.to_string_lossy(), - e - ))?; - } - } - None => { - if let Err(e) = opener::open(&path) { - let e = e.into(); - crate::display_warning_with_error("couldn't open docs", &e, shell); - } - } - }; - - Ok(()) -} diff --git a/src/cargo/ops/cargo_report/mod.rs b/src/cargo/ops/cargo_report/mod.rs new file mode 100644 index 00000000000..d0100992377 --- /dev/null +++ b/src/cargo/ops/cargo_report/mod.rs @@ -0,0 +1 @@ +pub mod timings; diff --git a/src/cargo/ops/cargo_report/timings.rs b/src/cargo/ops/cargo_report/timings.rs new file mode 100644 index 00000000000..666dc8467fb --- /dev/null +++ b/src/cargo/ops/cargo_report/timings.rs @@ -0,0 +1,386 @@ +//! The `cargo report timings` command. + +use std::ffi::OsStr; +use std::fs::File; +use std::io::BufReader; +use std::path::Path; +use std::path::PathBuf; + +use annotate_snippets::Level; +use anyhow::Context as _; +use cargo_util::paths; +use indexmap::IndexMap; +use indexmap::map::Entry; +use itertools::Itertools as _; +use tempfile::TempDir; + +use crate::AlreadyPrintedError; +use crate::CargoResult; +use crate::GlobalContext; +use crate::core::Workspace; +use crate::core::compiler::CompileMode; +use crate::core::compiler::timings::CompilationSection; +use crate::core::compiler::timings::UnitData; +use crate::core::compiler::timings::report::RenderContext; +use crate::core::compiler::timings::report::aggregate_sections; +use crate::core::compiler::timings::report::compute_concurrency; +use crate::core::compiler::timings::report::round_to_centisecond; +use crate::core::compiler::timings::report::write_html; +use crate::util::BuildLogger; +use crate::util::important_paths::find_root_manifest_for_wd; +use crate::util::log_message::LogMessage; +use crate::util::logger::RunId; +use crate::util::style; + +pub struct ReportTimingsOptions<'gctx> { + /// Whether to attempt to open the browser after the report is generated + pub open_result: bool, + pub gctx: &'gctx GlobalContext, +} + +/// Collects sections data for later post-processing through [`aggregate_sections`]. +struct UnitEntry { + data: UnitData, + sections: IndexMap, + rmeta_time: Option, +} + +pub fn report_timings(gctx: &GlobalContext, opts: ReportTimingsOptions<'_>) -> CargoResult<()> { + let ws = find_root_manifest_for_wd(gctx.cwd()) + .ok() + .and_then(|manifest_path| Workspace::new(&manifest_path, gctx).ok()); + let Some((log, run_id)) = select_log_file(gctx, ws.as_ref())? else { + let title_extra = if let Some(ws) = ws { + format!(" for workspace at `{}`", ws.root().display()) + } else { + String::new() + }; + let title = format!("no build log files found{title_extra}"); + let note = "run command with `-Z build-analysis` to generate log files"; + let report = [Level::ERROR + .primary_title(title) + .element(Level::NOTE.message(note))]; + gctx.shell().print_report(&report, false)?; + return Err(AlreadyPrintedError::new(anyhow::anyhow!("")).into()); + }; + + let ctx = prepare_context(&log, &run_id) + .with_context(|| format!("failed to analyze log at `{}`", log.display()))?; + + // If we are in a workspace, + // put timing reports in /cargo-timings/` as usual for easy access. + // Otherwise in a temporary directory + let reports_dir = if let Some(ws) = ws { + let target_dir = ws.target_dir(); + let target_dir = target_dir.as_path_unlocked(); + paths::create_dir_all_excluded_from_backups_atomic(target_dir)?; + let timings_dir = target_dir.join("cargo-timings"); + paths::create_dir_all(&timings_dir)?; + timings_dir + } else if let Ok(path) = gctx.get_env("__CARGO_TEST_REPORT_TIMINGS_TEMPDIR") { + PathBuf::from(path.to_owned()) + } else { + TempDir::with_prefix("cargo-timings-")?.keep() + }; + + let timing_path = reports_dir.join(format!("cargo-timing-{run_id}.html")); + + let mut out_file = std::fs::OpenOptions::new() + .write(true) + .create(true) + .truncate(true) + .open(&timing_path) + .with_context(|| format!("failed to open `{}`", timing_path.display()))?; + + write_html(ctx, &mut out_file)?; + + let link = gctx.shell().err_file_hyperlink(&timing_path); + let msg = format!("report saved to {link}{}{link:#}", timing_path.display()); + gctx.shell() + .status_with_color("Timing", msg, &style::NOTE)?; + + if opts.open_result { + crate::util::open::open(&timing_path, gctx)?; + } + + Ok(()) +} + +/// Selects the appropriate log file. +/// +/// Currently look at the newest log file for the workspace. +/// If not in a workspace, pick the newest log file in the log directory. +fn select_log_file( + gctx: &GlobalContext, + ws: Option<&Workspace<'_>>, +) -> CargoResult> { + let log_dir = gctx.home().join("log"); + let log_dir = log_dir.as_path_unlocked(); + + if !log_dir.exists() { + return Ok(None); + } + + // Gets the latest log files in the log directory + let mut walk = walkdir::WalkDir::new(log_dir) + .follow_links(true) + .sort_by(|a, b| a.file_name().cmp(b.file_name()).reverse()) + .min_depth(1) + .max_depth(1) + .into_iter() + .filter_map(|entry| { + let entry = entry.ok()?; + let path = entry.path(); + + // We only accept JSONL/NDJSON files. + if !entry.file_type().is_file() { + return None; + } + if entry.path().extension() != Some(OsStr::new("jsonl")) { + return None; + } + + // ...and the file name must follow RunId format + let run_id = path.file_stem()?.to_str()?.parse::().ok()?; + Some((entry, run_id)) + }); + + let item = if let Some(ws) = ws { + // If we are under a workspace, find only that workspace's log files. + let ws_run_id = BuildLogger::generate_run_id(ws); + walk.skip_while(|(_, run_id)| !run_id.same_workspace(&ws_run_id)) + .next() + } else { + walk.next() + }; + + Ok(item.map(|(entry, run_id)| (entry.into_path(), run_id))) +} + +fn prepare_context(log: &Path, run_id: &RunId) -> CargoResult> { + let reader = BufReader::new(File::open(&log)?); + + let mut ctx = RenderContext { + start_str: run_id.timestamp().to_string(), + root_units: Default::default(), + profile: Default::default(), + total_fresh: Default::default(), + total_dirty: Default::default(), + unit_data: Default::default(), + concurrency: Default::default(), + cpu_usage: Default::default(), + rustc_version: Default::default(), + host: Default::default(), + requested_targets: Default::default(), + jobs: 0, + num_cpus: None, + error: &None, + }; + let mut units: IndexMap<_, UnitEntry> = IndexMap::new(); + + for (log_index, result) in serde_json::Deserializer::from_reader(reader) + .into_iter::() + .enumerate() + { + let msg = match result { + Ok(msg) => msg, + Err(e) => { + tracing::warn!("failed to parse log message at index {log_index}: {e}"); + continue; + } + }; + + match msg { + LogMessage::BuildStarted { + cwd: _, + host, + jobs, + num_cpus, + profile, + rustc_version, + rustc_version_verbose: _, + target_dir: _, + workspace_root: _, + } => { + ctx.host = host; + ctx.jobs = jobs; + ctx.num_cpus = num_cpus; + ctx.profile = profile; + ctx.rustc_version = rustc_version; + } + LogMessage::UnitStarted { + package_id, + target, + mode, + index, + elapsed, + } => { + let version = package_id + .version() + .map(|v| v.to_string()) + .unwrap_or_else(|| "N/A".into()); + + // This is pretty similar to how the current `core::compiler::timings` + // renders `core::manifest::Target`. However, our target is + // a simplified type so we cannot reuse the same logic here. + let mut target_str = if target.kind == "lib" && mode == CompileMode::Build { + // Special case for brevity, since most dependencies hit this path. + "".to_string() + } else if target.kind == "build-script" { + " build-script".to_string() + } else { + format!(r#" {} "{}""#, target.name, target.kind) + }; + + match mode { + CompileMode::Test => target_str.push_str(" (test)"), + CompileMode::Build => {} + CompileMode::Check { test: true } => target_str.push_str(" (check-test)"), + CompileMode::Check { test: false } => target_str.push_str(" (check)"), + CompileMode::Doc { .. } => target_str.push_str(" (doc)"), + CompileMode::Doctest => target_str.push_str(" (doc test)"), + CompileMode::Docscrape => target_str.push_str(" (doc scrape)"), + CompileMode::RunCustomBuild => target_str.push_str(" (run)"), + } + + let mode_str = if mode.is_run_custom_build() { + "run-custom-build" + } else { + "todo" + }; + + let data = UnitData { + i: index, + name: package_id.name().to_string(), + version, + mode: mode_str.to_owned(), + target: target_str, + features: Vec::new(), + start: elapsed, + duration: 0.0, + unblocked_units: Vec::new(), + unblocked_rmeta_units: Vec::new(), + sections: None, + }; + + units.insert( + index, + UnitEntry { + data, + sections: IndexMap::new(), + rmeta_time: None, + }, + ); + } + LogMessage::UnitRmetaFinished { + index, + elapsed, + unblocked, + } => match units.entry(index) { + Entry::Occupied(mut e) => { + let elapsed = f64::max(elapsed - e.get().data.start, 0.0); + e.get_mut().data.unblocked_rmeta_units = unblocked; + e.get_mut().data.duration = elapsed; + e.get_mut().rmeta_time = Some(elapsed); + } + Entry::Vacant(_) => { + tracing::warn!( + "section `frontend` ended, but unit {index} has no start recorded" + ) + } + }, + LogMessage::UnitSectionStarted { + index, + elapsed, + section, + } => match units.entry(index) { + Entry::Occupied(mut e) => { + let elapsed = f64::max(elapsed - e.get().data.start, 0.0); + if e.get_mut() + .sections + .insert( + section.clone(), + CompilationSection { + start: elapsed, + end: None, + }, + ) + .is_some() + { + tracing::warn!( + "section `{section}` for unit {index} started more than once", + ); + } + } + Entry::Vacant(_) => { + tracing::warn!( + "section `{section}` started, but unit {index} has no start recorded" + ) + } + }, + LogMessage::UnitSectionFinished { + index, + elapsed, + section, + } => match units.entry(index) { + Entry::Occupied(mut e) => { + let elapsed = f64::max(elapsed - e.get().data.start, 0.0); + if let Some(section) = e.get_mut().sections.get_mut(§ion) { + section.end = Some(elapsed); + } else { + tracing::warn!( + "section `{section}` for unit {index} ended, but section `{section}` has no start recorded" + ); + } + } + Entry::Vacant(_) => { + tracing::warn!( + "section `{section}` ended, but unit {index} has no start recorded" + ) + } + }, + LogMessage::UnitFinished { + index, + elapsed, + unblocked, + } => match units.entry(index) { + Entry::Occupied(mut e) => { + let elapsed = f64::max(elapsed - e.get().data.start, 0.0); + e.get_mut().data.duration = elapsed; + e.get_mut().data.unblocked_units = unblocked; + } + Entry::Vacant(_) => { + tracing::warn!("unit {index} ended, but it has no start recorded"); + } + }, + _ => {} // skip non-timing logs + } + } + + let unit_data: Vec<_> = units + .into_values() + .map( + |UnitEntry { + mut data, + sections, + rmeta_time, + }| { + // Post-processing for compilation sections we've collected so far. + data.sections = aggregate_sections(sections, data.duration, rmeta_time); + data.start = round_to_centisecond(data.start); + data.duration = round_to_centisecond(data.duration); + data + }, + ) + .sorted_unstable_by(|a, b| a.start.partial_cmp(&b.start).unwrap()) + .collect(); + + if unit_data.is_empty() { + anyhow::bail!("no timing data found in log"); + } + + ctx.unit_data = unit_data; + ctx.concurrency = compute_concurrency(&ctx.unit_data); + + Ok(ctx) +} diff --git a/src/cargo/ops/mod.rs b/src/cargo/ops/mod.rs index 2fa8b592748..dee8ec4e719 100644 --- a/src/cargo/ops/mod.rs +++ b/src/cargo/ops/mod.rs @@ -17,6 +17,8 @@ pub use self::cargo_package::check_yanked; pub use self::cargo_package::package; pub use self::cargo_pkgid::pkgid; pub use self::cargo_read_manifest::read_package; +pub use self::cargo_report::timings::ReportTimingsOptions; +pub use self::cargo_report::timings::report_timings; pub use self::cargo_run::run; pub use self::cargo_test::{TestOptions, run_benches, run_tests}; pub use self::cargo_uninstall::uninstall; @@ -61,6 +63,7 @@ mod cargo_package; mod cargo_pkgid; mod cargo_read_manifest; pub mod cargo_remove; +mod cargo_report; mod cargo_run; mod cargo_test; mod cargo_uninstall; diff --git a/src/cargo/util/mod.rs b/src/cargo/util/mod.rs index 7b29d830a30..367d51ba2ac 100644 --- a/src/cargo/util/mod.rs +++ b/src/cargo/util/mod.rs @@ -61,6 +61,7 @@ pub mod logger; pub mod machine_message; pub mod network; mod once; +pub mod open; mod progress; mod queue; pub mod restricted_names; diff --git a/src/cargo/util/open.rs b/src/cargo/util/open.rs new file mode 100644 index 00000000000..5f94c89ed73 --- /dev/null +++ b/src/cargo/util/open.rs @@ -0,0 +1,48 @@ +//! For opening files or URLs with the preferred application. + +use std::path::Path; +use std::path::PathBuf; +use std::process::Command; + +use crate::CargoResult; +use crate::GlobalContext; +use crate::util::context::PathAndArgs; + +/// Opens a file path using the preferred application. +/// +/// 1. Try `doc.browser` config first +/// 2. Then `$BROWSER` +/// 3. Finally system default opener +pub fn open(path: &Path, gctx: &GlobalContext) -> CargoResult<()> { + let config_browser = { + let cfg: Option = gctx.get("doc.browser")?; + cfg.map(|path_args| (path_args.path.resolve_program(gctx), path_args.args)) + }; + + let mut shell = gctx.shell(); + let link = shell.err_file_hyperlink(&path); + shell.status("Opening", format!("{link}{}{link:#}", path.display()))?; + + let browser = + config_browser.or_else(|| Some((PathBuf::from(gctx.get_env_os("BROWSER")?), Vec::new()))); + + match browser { + Some((browser, initial_args)) => { + if let Err(e) = Command::new(&browser).args(initial_args).arg(path).status() { + shell.warn(format!( + "Couldn't open docs with {}: {}", + browser.to_string_lossy(), + e + ))?; + } + } + None => { + if let Err(e) = opener::open(&path) { + let e = e.into(); + crate::display_warning_with_error("couldn't open docs", &e, &mut shell); + } + } + }; + + Ok(()) +} diff --git a/tests/testsuite/build_analysis.rs b/tests/testsuite/build_analysis.rs index b8528052d61..2f11ab24055 100644 --- a/tests/testsuite/build_analysis.rs +++ b/tests/testsuite/build_analysis.rs @@ -4,7 +4,7 @@ use crate::prelude::*; use cargo_test_support::basic_manifest; use cargo_test_support::compare::assert_e2e; -use cargo_test_support::paths; +use cargo_test_support::paths::log_file; use cargo_test_support::project; use cargo_test_support::str; @@ -509,27 +509,6 @@ fn log_rebuild_reason_no_rebuild() { ); } -/// This also asserts the number of log files is exactly the same as `idx + 1`. fn get_log(idx: usize) -> String { - let cargo_home = paths::cargo_home(); - let log_dir = cargo_home.join("log"); - - let entries = std::fs::read_dir(&log_dir).unwrap(); - let mut log_files: Vec<_> = entries - .filter_map(Result::ok) - .filter(|e| e.path().extension().and_then(|s| s.to_str()) == Some("jsonl")) - .collect(); - - // Sort them to get chronological order - log_files.sort_unstable_by(|a, b| a.file_name().to_str().cmp(&b.file_name().to_str())); - - assert_eq!( - idx + 1, - log_files.len(), - "unexpected number of log files: {}, expected {}", - log_files.len(), - idx + 1 - ); - - std::fs::read_to_string(log_files[idx].path()).unwrap() + std::fs::read_to_string(log_file(idx)).unwrap() } diff --git a/tests/testsuite/cargo_report/help/stdout.term.svg b/tests/testsuite/cargo_report/help/stdout.term.svg index e7339ad9aad..2b6f39f4673 100644 --- a/tests/testsuite/cargo_report/help/stdout.term.svg +++ b/tests/testsuite/cargo_report/help/stdout.term.svg @@ -1,7 +1,7 @@ - + + Cargo Build Timings — + + + + + +

Cargo Build Timings

+See Documentation + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + +
Targets:
Profile:dev
Fresh units:0
Dirty units:0
Total units:0
Max concurrency:11 (jobs=10 ncpu=10)
Build start:2006-07-24T01:21:28Z
Total time:10.1s
rustc:1.94.0-nightly
Host: [..]
Target: [..]
+ + + + + + + + + + + + + + + +
+ +
+ +
+ + +
+
+ +
+ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + +
UnitTotalFrontendCodegenLinkFeatures
1.jiff v0.2.162.6s1.9s (74%)0.5s (21%)0.1s (4%)
2.serde_derive v1.0.2281.7s1.0s (59%)0.3s (18%)0.4s (22%)
3.thiserror-impl v2.0.171.4s0.4s (27%)0.3s (20%)0.8s (53%)
4.serde_core v1.0.228 build-script1.4s0.1s (7%)0.1s (7%)1.2s (86%)
5.proc-macro2 v1.0.103 build-script1.4s0.1s (8%)0.1s (7%)1.2s (85%)
6.serde_core v1.0.228 build-script (run)1.3s
7.quote v1.0.42 build-script1.3s0.1s (8%)0.1s (7%)1.1s (84%)
8.icu_properties_data v2.1.1 build-script1.3s0.1s (6%)0.0s (1%)1.2s (91%)
9.icu_normalizer_data v2.1.1 build-script1.3s0.1s (7%)0.0s (1%)1.1s (90%)
10.thiserror v2.0.17 build-script (run)1.3s
11.zerofrom-derive v0.1.61.2s0.2s (15%)0.2s (20%)0.8s (63%)
12.syn v2.0.1111.2s0.9s (73%)0.3s (24%)0.0s (2%)
13.typeid v1.0.3 build-script1.2s0.1s (6%)0.1s (4%)1.1s (89%)
14.zerovec-derive v0.11.21.2s0.3s (29%)0.3s (21%)0.6s (50%)
15.num-traits v0.2.19 build-script (run)1.2s
16.typeid v1.0.3 build-script (run)1.2s
17.serde v1.0.228 build-script1.2s0.1s (6%)0.1s (6%)1.0s (87%)
18.serde_core v1.0.2281.2s1.0s (86%)0.1s (12%)0.0s (1%)
19.cargo-util-schemas v0.12.01.1s0.8s (74%)0.3s (24%)0.0s (3%)
20.erased-serde v0.4.9 build-script1.0s0.1s (7%)0.1s (5%)0.9s (88%)
21.displaydoc v0.2.51.0s0.2s (17%)0.2s (21%)0.6s (62%)
22.yoke-derive v0.8.11.0s0.2s (18%)0.2s (19%)0.6s (62%)
23.proc-macro2 v1.0.103 build-script (run)1.0s
24.icu_properties_data v2.1.1 build-script (run)0.9s
25.num-traits v0.2.19 build-script0.9s0.0s (5%)0.0s (1%)0.8s (93%)
26.thiserror v2.0.17 build-script0.9s0.0s (6%)0.1s (7%)0.8s (87%)
27.zerovec v0.11.50.7s0.6s (93%)0.0s (3%)0.0s (1%)
28.erased-serde v0.4.9 build-script (run)0.7s
29.serde v1.0.2280.7s0.6s (88%)0.1s (10%)0.0s (0%)
30.icu_properties v2.1.10.6s0.5s (78%)0.1s (20%)0.0s (0%)
31.quote v1.0.42 build-script (run)0.6s
32.serde v1.0.228 build-script (run)0.5s
33.autocfg v1.5.00.5s0.2s (44%)0.3s (54%)0.0s (4%)
34.icu_locale_core v2.1.10.5s0.3s (72%)0.1s (26%)0.0s (0%)
35.num-traits v0.2.190.4s0.4s (86%)0.1s (12%)0.0s (2%)
36.toml v0.9.80.4s0.2s (54%)0.2s (41%)0.0s (5%)
37.zerotrie v0.2.30.4s0.4s (88%)0.0s (9%)0.0s (0%)
38.erased-serde v0.4.90.4s0.3s (70%)0.1s (22%)0.0s (5%)
39.url v2.5.70.4s0.3s (69%)0.1s (27%)0.0s (3%)
40.synstructure v0.13.20.4s0.2s (45%)0.2s (49%)0.0s (3%)
41.thiserror v2.0.170.4s0.3s (97%)0.0s (1%)0.0s (3%)
42.icu_normalizer_data v2.1.1 build-script (run)0.3s
43.yoke v0.8.10.3s0.3s (96%)0.0s (1%)0.0s (3%)
44.semver v1.0.270.3s0.2s (51%)0.1s (43%)0.0s (3%)
45.proc-macro2 v1.0.1030.3s0.2s (66%)0.1s (31%)0.0s (3%)
46.icu_normalizer v2.1.10.3s0.2s (64%)0.1s (34%)0.0s (4%)
47.idna v1.1.00.3s0.1s (50%)0.1s (46%)0.0s (4%)
48.serde-untagged v0.1.90.3s0.2s (77%)0.0s (17%)0.0s (4%)
49.toml_datetime v0.7.30.3s0.2s (59%)0.1s (37%)0.0s (0%)
50.zerofrom v0.1.60.3s0.2s (89%)0.0s (7%)0.0s (0%)
51.icu_collections v2.1.10.2s0.2s (69%)0.1s (31%)0.0s (0%)
52.writeable v0.6.20.2s0.2s (80%)0.0s (16%)0.0s (0%)
53.percent-encoding v2.3.20.2s0.1s (71%)0.0s (24%)0.0s (0%)
54.serde-value v0.7.00.2s0.1s (63%)0.1s (34%)0.0s (0%)
55.litemap v0.8.10.2s0.2s (78%)0.0s (10%)0.0s (5%)
56.icu_provider v2.1.10.2s0.1s (72%)0.0s (20%)0.0s (0%)
57.smallvec v1.15.10.2s0.1s (79%)0.0s (12%)0.0s (6%)
58.quote v1.0.420.2s0.1s (62%)0.0s (27%)0.0s (0%)
59.unicode-ident v1.0.220.1s0.1s (70%)0.0s (20%)0.0s (7%)
60.serde_spanned v1.0.30.1s0.1s (69%)0.0s (17%)0.0s (7%)
61.ordered-float v2.10.10.1s0.1s (81%)0.0s (11%)0.0s (0%)
62.icu_properties_data v2.1.10.1s0.1s (83%)0.0s (6%)0.0s (0%)
63.tinystr v0.8.20.1s0.1s (79%)0.0s (12%)0.0s (9%)
64.form_urlencoded v1.2.20.1s0.1s (63%)0.0s (33%)0.0s (10%)
65.stable_deref_trait v1.2.10.1s0.1s (77%)0.0s (5%)0.0s (10%)
66.potential_utf v0.1.40.1s0.1s (69%)0.0s (23%)0.0s (0%)
67.utf8_iter v1.0.40.1s0.1s (71%)0.0s (12%)0.0s (0%)
68.idna_adapter v1.2.10.1s0.1s (75%)0.0s (17%)0.0s (0%)
69.typeid v1.0.30.1s0.0s (73%)0.0s (24%)0.0s (17%)
70.icu_normalizer_data v2.1.10.1s0.0s (70%)0.0s (19%)0.0s (0%)
+ + + diff --git a/tests/testsuite/cargo_report_timings/html_snapshot/stderr.term.svg b/tests/testsuite/cargo_report_timings/html_snapshot/stderr.term.svg new file mode 100644 index 00000000000..bf8d983a05c --- /dev/null +++ b/tests/testsuite/cargo_report_timings/html_snapshot/stderr.term.svg @@ -0,0 +1,27 @@ + + + + + + + Timing report saved to [ROOT]/case/cargo-timing-20060724T012128000Z-b0fd440798ab3cfb.html + + + + + + diff --git a/tests/testsuite/cargo_report_timings/mod.rs b/tests/testsuite/cargo_report_timings/mod.rs new file mode 100644 index 00000000000..f5a1bae0370 --- /dev/null +++ b/tests/testsuite/cargo_report_timings/mod.rs @@ -0,0 +1,315 @@ +//! Tests for `cargo report timings`. + +mod help; +mod html_snapshot; + +use crate::prelude::*; +use crate::utils::cargo_process; + +use cargo_test_support::basic_manifest; +use cargo_test_support::paths; +use cargo_test_support::project; +use cargo_test_support::str; + +#[cargo_test] +fn gated_stable_channel() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + p.cargo("report timings") + .with_status(101) + .with_stderr_data(str![[r#" +[ERROR] the `cargo report timings` command is unstable, and only available on the nightly channel of Cargo, but this is the `stable` channel +See https://doc.rust-lang.org/book/appendix-07-nightly-rust.html for more information about Rust release channels. +See https://github.com/rust-lang/cargo/issues/15844 for more information about the `cargo report timings` command. + +"#]]) + .run(); +} + +#[cargo_test] +fn gated_unstable_options() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + p.cargo("report timings") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_status(101) + .with_stderr_data(str![[r#" +[ERROR] the `cargo report timings` command is unstable, pass `-Z build-analysis` to enable it +See https://github.com/rust-lang/cargo/issues/15844 for more information about the `cargo report timings` command. + +"#]]) + .run(); +} + +#[cargo_test] +fn no_log() { + cargo_process("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_status(101) + .with_stderr_data(str![[r#" +[ERROR] no build log files found + | + = [NOTE] run command with `-Z build-analysis` to generate log files + +"#]]) + .run(); +} + +#[cargo_test] +fn no_log_for_the_current_workspace() { + let foo = project() + .at("foo") + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + foo.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // one log file got generated. + let _ = paths::log_file(0); + + let bar = project() + .at("bar") + .file("Cargo.toml", &basic_manifest("bar", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + bar.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_status(101) + .with_stderr_data(str![[r#" +[ERROR] no build log files found for workspace at `[ROOT]/bar` + | + = [NOTE] run command with `-Z build-analysis` to generate log files + +"#]]) + .run(); +} + +#[cargo_test] +fn invalid_log() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + p.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // Put some junks in the log file. + std::fs::write(paths::log_file(0), "}|x| hello world").unwrap(); + + p.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_status(101) + .with_stderr_data(str![[r#" +[ERROR] failed to analyze log at `[ROOT]/home/.cargo/log/[..]T[..]Z-[..].jsonl` + +Caused by: + no timing data found in log + +"#]]) + .run(); +} + +#[cargo_test] +fn empty_log() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + p.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // Truncate the log file. + std::fs::File::create(paths::log_file(0)).unwrap(); + + // If the make-up log file was picked, the command would have failed. + p.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_status(101) + .with_stderr_data(str![[r#" +[ERROR] failed to analyze log at `[ROOT]/home/.cargo/log/[..]T[..]Z-[..].jsonl` + +Caused by: + no timing data found in log + +"#]]) + .run(); +} + +#[cargo_test] +fn prefer_latest() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + p.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // Put some junks in the first log file. + std::fs::write(paths::log_file(0), "}|x| hello world").unwrap(); + + p.change_file("src/lib.rs", "pub fn foo() {}"); + p.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // the second log file got generated. + let _ = paths::log_file(1); + + // if it had picked the corrupted first log file, it would have failed. + p.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_stderr_data(str![[r#" + Timing report saved to [ROOT]/foo/target/cargo-timings/cargo-timing-[..]T[..]Z-[..].html + +"#]]) + .run(); + + assert_eq!(p.glob("**/cargo-timing-*.html").count(), 1); +} + +#[cargo_test] +fn prefer_workspace() { + let foo = project() + .at("foo") + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + foo.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // one log file got generated. + let _ = paths::log_file(0); + + let bar = project() + .at("bar") + .file("Cargo.toml", &basic_manifest("bar", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + bar.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // Put some junks in the newest log file. + std::fs::write(paths::log_file(1), "}|x| hello world").unwrap(); + + // Back to foo, if it had picked the corrupted log file, it would have failed. + foo.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_stderr_data(str![[r#" + Timing report saved to [ROOT]/foo/target/cargo-timings/cargo-timing-[..]T[..]Z-[..].html + +"#]]) + .run(); + + assert_eq!(foo.glob("**/cargo-timing-*.html").count(), 1); +} + +#[cargo_test] +fn outside_workspace() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "") + .build(); + + p.cargo("build -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + // cd to outside the workspace, it should + // * retrieve the latest log + // * save the report in a temp directory + cargo_process("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_stderr_data(str![[r#" + Timing report saved to [..]/cargo-timing-[..]T[..]Z-[..].html + +"#]]) + .run(); + + // Have no timing HTML under target directory + assert_eq!(p.glob("**/cargo-timing-*.html").count(), 0); +} + +#[cargo_test(nightly, reason = "rustc --json=timings is unstable")] +fn with_section_timings() { + let p = project() + .file("Cargo.toml", &basic_manifest("foo", "0.0.0")) + .file("src/lib.rs", "pub fn foo() {}") + .build(); + + p.cargo("check -Zbuild-analysis -Zsection-timings") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis", "section-timings"]) + .run(); + + p.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_stderr_data(str![[r#" + Timing report saved to [ROOT]/foo/target/cargo-timings/cargo-timing-[..]T[..]Z-[..].html + +"#]]) + .run(); + + assert_eq!(p.glob("**/cargo-timing-*.html").count(), 1); +} + +#[cargo_test] +fn with_multiple_targets() { + let p = project() + .file( + "Cargo.toml", + r#" + [package] + name = "foo" + edition = "2021" + "#, + ) + .file("src/lib.rs", "pub fn lib_fn() {}") + .file("src/main.rs", "fn main() {}") + .file("src/bin/extra.rs", "fn main() {}") + .file("examples/ex1.rs", "fn main() {}") + .file("tests/t1.rs", "#[test] fn test1() {}") + .build(); + + p.cargo("build --all-targets -Zbuild-analysis") + .env("CARGO_BUILD_ANALYSIS_ENABLED", "true") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .run(); + + p.cargo("report timings -Zbuild-analysis") + .masquerade_as_nightly_cargo(&["build-analysis"]) + .with_stderr_data(str![[r#" + Timing report saved to [ROOT]/foo/target/cargo-timings/cargo-timing-[..]T[..]Z-[..].html + +"#]]) + .run(); + + assert_eq!(p.glob("**/cargo-timing-*.html").count(), 1); +} diff --git a/tests/testsuite/main.rs b/tests/testsuite/main.rs index f8f03b5fedb..ccc489b07d1 100644 --- a/tests/testsuite/main.rs +++ b/tests/testsuite/main.rs @@ -52,6 +52,7 @@ mod cargo_publish; mod cargo_read_manifest; mod cargo_remove; mod cargo_report; +mod cargo_report_timings; mod cargo_run; mod cargo_rustc; mod cargo_rustdoc;