From e6dddcb8ec095dc520be16f7c45b91de8c55b10a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Sun, 10 Aug 2025 21:13:50 +0200 Subject: [PATCH 01/18] Store bootstrap tracing outputs to a unified directory --- src/bootstrap/src/bin/main.rs | 25 ++++++++++++++++++++----- src/bootstrap/src/lib.rs | 8 ++++---- src/bootstrap/src/utils/exec.rs | 19 ++++--------------- src/bootstrap/src/utils/step_graph.rs | 10 ++++++---- 4 files changed, 34 insertions(+), 28 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index cf24fedaebb15..70db6fad0f601 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -18,10 +18,14 @@ use bootstrap::{ #[cfg(feature = "tracing")] use tracing::instrument; -fn is_bootstrap_profiling_enabled() -> bool { +fn is_profiling_enabled() -> bool { env::var("BOOTSTRAP_PROFILE").is_ok_and(|v| v == "1") } +fn is_tracing_enabled() -> bool { + is_profiling_enabled() || cfg!(feature = "tracing") +} + #[cfg_attr(feature = "tracing", instrument(level = "trace", name = "main"))] fn main() { #[cfg(feature = "tracing")] @@ -102,6 +106,13 @@ fn main() { let dump_bootstrap_shims = config.dump_bootstrap_shims; let out_dir = config.out.clone(); + let tracing_enabled = is_tracing_enabled(); + let tracing_dir = out_dir.join("bootstrap-trace").join(std::process::id().to_string()); + if tracing_enabled { + let _ = std::fs::remove_dir_all(&tracing_dir); + std::fs::create_dir_all(&tracing_dir).unwrap(); + } + debug!("creating new build based on config"); let mut build = Build::new(config); build.build(); @@ -156,12 +167,16 @@ fn main() { } } - if is_bootstrap_profiling_enabled() { - build.report_summary(start_time); + if is_profiling_enabled() { + build.report_summary(&tracing_dir.join("command-stats.txt"), start_time); } #[cfg(feature = "tracing")] - build.report_step_graph(); + build.report_step_graph(&tracing_dir); + + if tracing_enabled { + eprintln!("Tracing/profiling output has been written to {}", tracing_dir.display()); + } } fn check_version(config: &Config) -> Option { @@ -241,7 +256,7 @@ fn setup_tracing() -> impl Drop { let mut chrome_layer = tracing_chrome::ChromeLayerBuilder::new().include_args(true); // Writes the Chrome profile to trace-.json if enabled - if !is_bootstrap_profiling_enabled() { + if !is_profiling_enabled() { chrome_layer = chrome_layer.writer(io::sink()); } diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs index 4abf386e5de61..b02c1081a7469 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -2016,13 +2016,13 @@ to download LLVM rather than building it. &self.config.exec_ctx } - pub fn report_summary(&self, start_time: Instant) { - self.config.exec_ctx.profiler().report_summary(start_time); + pub fn report_summary(&self, path: &Path, start_time: Instant) { + self.config.exec_ctx.profiler().report_summary(path, start_time); } #[cfg(feature = "tracing")] - pub fn report_step_graph(self) { - self.step_graph.into_inner().store_to_dot_files(); + pub fn report_step_graph(self, directory: &Path) { + self.step_graph.into_inner().store_to_dot_files(directory); } } diff --git a/src/bootstrap/src/utils/exec.rs b/src/bootstrap/src/utils/exec.rs index 03760faec690b..ff79a1765526e 100644 --- a/src/bootstrap/src/utils/exec.rs +++ b/src/bootstrap/src/utils/exec.rs @@ -15,7 +15,6 @@ use std::hash::Hash; use std::io::{BufWriter, Write}; use std::panic::Location; use std::path::Path; -use std::process; use std::process::{ Child, ChildStderr, ChildStdout, Command, CommandArgs, CommandEnvs, ExitStatus, Output, Stdio, }; @@ -26,10 +25,10 @@ use build_helper::ci::CiEnv; use build_helper::drop_bomb::DropBomb; use build_helper::exit; -use crate::PathBuf; use crate::core::config::DryRun; #[cfg(feature = "tracing")] use crate::trace_cmd; +use crate::{PathBuf, t}; /// What should be done when the command fails. #[derive(Debug, Copy, Clone)] @@ -121,17 +120,9 @@ impl CommandProfiler { entry.traces.push(ExecutionTrace::CacheHit); } - pub fn report_summary(&self, start_time: Instant) { - let pid = process::id(); - let filename = format!("bootstrap-profile-{pid}.txt"); - - let file = match File::create(&filename) { - Ok(f) => f, - Err(e) => { - eprintln!("Failed to create profiler output file: {e}"); - return; - } - }; + /// Report summary of executed commands file at the specified `path`. + pub fn report_summary(&self, path: &Path, start_time: Instant) { + let file = t!(File::create(path)); let mut writer = BufWriter::new(file); let stats = self.stats.lock().unwrap(); @@ -221,8 +212,6 @@ impl CommandProfiler { writeln!(writer, "Total cache hits: {total_cache_hits}").unwrap(); writeln!(writer, "Estimated time saved due to cache hits: {total_saved_duration:.2?}") .unwrap(); - - println!("Command profiler report saved to {filename}"); } } diff --git a/src/bootstrap/src/utils/step_graph.rs b/src/bootstrap/src/utils/step_graph.rs index c45825a42223a..30a7853b81664 100644 --- a/src/bootstrap/src/utils/step_graph.rs +++ b/src/bootstrap/src/utils/step_graph.rs @@ -1,8 +1,10 @@ use std::collections::{HashMap, HashSet}; use std::fmt::Debug; use std::io::BufWriter; +use std::path::Path; use crate::core::builder::{AnyDebug, Step}; +use crate::t; /// Records the executed steps and their dependencies in a directed graph, /// which can then be rendered into a DOT file for visualization. @@ -80,10 +82,10 @@ impl StepGraph { } } - pub fn store_to_dot_files(self) { + pub fn store_to_dot_files(self, directory: &Path) { for (key, graph) in self.graphs.into_iter() { - let filename = format!("bootstrap-steps{key}.dot"); - graph.render(&filename).unwrap(); + let filename = directory.join(format!("step-graph{key}.dot")); + t!(graph.render(&filename)); } } } @@ -147,7 +149,7 @@ impl DotGraph { self.key_to_index.get(key).copied() } - fn render(&self, path: &str) -> std::io::Result<()> { + fn render(&self, path: &Path) -> std::io::Result<()> { use std::io::Write; let mut file = BufWriter::new(std::fs::File::create(path)?); From c97b6065239b319182465a04c2989002a62d0a9d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Sun, 10 Aug 2025 21:20:27 +0200 Subject: [PATCH 02/18] Store `latest` symlink to the latest tracing output directory --- src/bootstrap/src/bin/main.rs | 15 +++++++++++++-- src/bootstrap/src/lib.rs | 6 ++---- 2 files changed, 15 insertions(+), 6 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index 70db6fad0f601..c5ada88462f41 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -13,7 +13,7 @@ use std::{env, process}; use bootstrap::{ Build, CONFIG_CHANGE_HISTORY, ChangeId, Config, Flags, Subcommand, debug, - find_recent_config_change_ids, human_readable_changes, t, + find_recent_config_change_ids, human_readable_changes, symlink_dir, t, }; #[cfg(feature = "tracing")] use tracing::instrument; @@ -107,10 +107,21 @@ fn main() { let out_dir = config.out.clone(); let tracing_enabled = is_tracing_enabled(); + + // Prepare a directory for tracing output + // Also store a symlink named "latest" to point to the latest tracing directory. let tracing_dir = out_dir.join("bootstrap-trace").join(std::process::id().to_string()); + let latest_trace_dir = tracing_dir.parent().unwrap().join("latest"); if tracing_enabled { let _ = std::fs::remove_dir_all(&tracing_dir); std::fs::create_dir_all(&tracing_dir).unwrap(); + + #[cfg(windows)] + let _ = std::fs::remove_dir(&latest_trace_dir); + #[cfg(not(windows))] + let _ = std::fs::remove_file(&latest_trace_dir); + + t!(symlink_dir(&config, &tracing_dir, &latest_trace_dir)); } debug!("creating new build based on config"); @@ -175,7 +186,7 @@ fn main() { build.report_step_graph(&tracing_dir); if tracing_enabled { - eprintln!("Tracing/profiling output has been written to {}", tracing_dir.display()); + eprintln!("Tracing/profiling output has been written to {}", latest_trace_dir.display()); } } diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs index b02c1081a7469..7d6c0658f4754 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -37,9 +37,7 @@ use crate::core::builder; use crate::core::builder::Kind; use crate::core::config::{DryRun, LldMode, LlvmLibunwind, TargetSelection, flags}; use crate::utils::exec::{BootstrapCommand, command}; -use crate::utils::helpers::{ - self, dir_is_empty, exe, libdir, set_file_times, split_debuginfo, symlink_dir, -}; +use crate::utils::helpers::{self, dir_is_empty, exe, libdir, set_file_times, split_debuginfo}; mod core; mod utils; @@ -53,7 +51,7 @@ use tracing::{instrument, span}; pub use utils::change_tracker::{ CONFIG_CHANGE_HISTORY, find_recent_config_change_ids, human_readable_changes, }; -pub use utils::helpers::PanicTracker; +pub use utils::helpers::{PanicTracker, symlink_dir}; use crate::core::build_steps::vendor::VENDOR_DIR; From f819729539481f6ca302466caf527fa798815850 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Sun, 10 Aug 2025 21:41:26 +0200 Subject: [PATCH 03/18] Store Chrome step trace into the tracing directory --- src/bootstrap/Cargo.toml | 3 +- src/bootstrap/src/bin/main.rs | 59 +++++++++++++++++++++++++++-------- 2 files changed, 48 insertions(+), 14 deletions(-) diff --git a/src/bootstrap/Cargo.toml b/src/bootstrap/Cargo.toml index 8dc41d1dec697..ecb332eb7e3ad 100644 --- a/src/bootstrap/Cargo.toml +++ b/src/bootstrap/Cargo.toml @@ -7,7 +7,7 @@ default-run = "bootstrap" [features] build-metrics = ["sysinfo"] -tracing = ["dep:tracing", "dep:tracing-chrome", "dep:tracing-subscriber", "dep:tracing-forest"] +tracing = ["dep:tracing", "dep:tracing-chrome", "dep:tracing-subscriber", "dep:tracing-forest", "dep:tempfile"] [lib] path = "src/lib.rs" @@ -65,6 +65,7 @@ tracing = { version = "0.1", optional = true, features = ["attributes"] } tracing-chrome = { version = "0.7", optional = true } tracing-subscriber = { version = "0.3", optional = true, features = ["env-filter", "fmt", "registry", "std"] } tracing-forest = { version = "0.1.6", optional = true, default-features = false, features = ["smallvec", "ansi", "env-filter"] } +tempfile = { version = "3.15.0", optional = true } [target.'cfg(windows)'.dependencies.junction] version = "1.0.0" diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index c5ada88462f41..a078a519b85cd 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -29,7 +29,7 @@ fn is_tracing_enabled() -> bool { #[cfg_attr(feature = "tracing", instrument(level = "trace", name = "main"))] fn main() { #[cfg(feature = "tracing")] - let _guard = setup_tracing(); + let guard = setup_tracing(is_profiling_enabled()); let start_time = Instant::now(); @@ -183,7 +183,12 @@ fn main() { } #[cfg(feature = "tracing")] - build.report_step_graph(&tracing_dir); + { + build.report_step_graph(&tracing_dir); + if let Some(guard) = guard { + guard.copy_to_dir(&tracing_dir); + } + } if tracing_enabled { eprintln!("Tracing/profiling output has been written to {}", latest_trace_dir.display()); @@ -257,25 +262,53 @@ fn check_version(config: &Config) -> Option { // - `tracing`'s `#[instrument(..)]` macro will need to be gated like `#![cfg_attr(feature = // "tracing", instrument(..))]`. #[cfg(feature = "tracing")] -fn setup_tracing() -> impl Drop { +fn setup_tracing(profiling_enabled: bool) -> Option { + use std::fs::File; + use std::io::BufWriter; + use tracing_forest::ForestLayer; use tracing_subscriber::EnvFilter; use tracing_subscriber::layer::SubscriberExt; let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); - let mut chrome_layer = tracing_chrome::ChromeLayerBuilder::new().include_args(true); + let registry = tracing_subscriber::registry().with(filter).with(ForestLayer::default()); - // Writes the Chrome profile to trace-.json if enabled - if !is_profiling_enabled() { - chrome_layer = chrome_layer.writer(io::sink()); - } + let guard = if profiling_enabled { + // When we're creating this layer, we do not yet know the location of the tracing output + // directory, because it is stored in the output directory determined after Config is parsed, + // but we already want to make tracing calls during (and before) config parsing. + // So we store the output into a temporary file, and then move it to the tracing directory + // before bootstrap ends. + let tempdir = tempfile::TempDir::new().expect("Cannot create temporary directory"); + let chrome_tracing_path = tempdir.path().join("bootstrap-trace.json"); + let file = BufWriter::new(File::create(&chrome_tracing_path).unwrap()); - let (chrome_layer, _guard) = chrome_layer.build(); + let chrome_layer = + tracing_chrome::ChromeLayerBuilder::new().writer(file).include_args(true); + let (chrome_layer, guard) = chrome_layer.build(); - let registry = - tracing_subscriber::registry().with(filter).with(ForestLayer::default()).with(chrome_layer); + tracing::subscriber::set_global_default(registry.with(chrome_layer)).unwrap(); + Some(TracingGuard { guard, _tempdir: tempdir, chrome_tracing_path }) + } else { + tracing::subscriber::set_global_default(registry).unwrap(); + None + }; - tracing::subscriber::set_global_default(registry).unwrap(); - _guard + guard +} + +#[cfg(feature = "tracing")] +struct TracingGuard { + guard: tracing_chrome::FlushGuard, + _tempdir: tempfile::TempDir, + chrome_tracing_path: std::path::PathBuf, +} + +#[cfg(feature = "tracing")] +impl TracingGuard { + fn copy_to_dir(self, dir: &std::path::Path) { + drop(self.guard); + std::fs::rename(&self.chrome_tracing_path, dir.join("chrome-trace.json")).unwrap(); + } } From aad579537f2cb004f193511659b084f928c1ba51 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Sun, 10 Aug 2025 21:48:01 +0200 Subject: [PATCH 04/18] Use shorter command span label --- src/bootstrap/src/utils/tracing.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs index 109407bc5f235..4e596e35060f0 100644 --- a/src/bootstrap/src/utils/tracing.rs +++ b/src/bootstrap/src/utils/tracing.rs @@ -55,7 +55,7 @@ macro_rules! trace_cmd { ::tracing::span!( target: "COMMAND", ::tracing::Level::TRACE, - "executing command", + "cmd", cmd = $cmd.fingerprint().format_short_cmd(), full_cmd = ?$cmd ).entered() From 3a115ba69b58e5f3bca037f483ad93bf244c75f9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Sun, 10 Aug 2025 22:15:44 +0200 Subject: [PATCH 05/18] Print step timings also when the stap starts to execute So that it is easier to see which was the last started step when a failure happens on CI. --- src/bootstrap/src/core/builder/mod.rs | 24 ++++++++++++++++++------ 1 file changed, 18 insertions(+), 6 deletions(-) diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs index 163a498d4b48c..fc454ebe81971 100644 --- a/src/bootstrap/src/core/builder/mod.rs +++ b/src/bootstrap/src/core/builder/mod.rs @@ -1700,10 +1700,15 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s #[cfg(feature = "build-metrics")] self.metrics.enter_step(&step, self); + if self.config.print_step_timings && !self.config.dry_run() { + println!("[TIMING:start] {}", pretty_print_step(&step)); + } + let (out, dur) = { let start = Instant::now(); let zero = Duration::new(0, 0); let parent = self.time_spent_on_dependencies.replace(zero); + let out = step.clone().run(self); let dur = start.elapsed(); let deps = self.time_spent_on_dependencies.replace(parent + dur); @@ -1711,13 +1716,9 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s }; if self.config.print_step_timings && !self.config.dry_run() { - let step_string = format!("{step:?}"); - let brace_index = step_string.find('{').unwrap_or(0); - let type_string = type_name::(); println!( - "[TIMING] {} {} -- {}.{:03}", - &type_string.strip_prefix("bootstrap::").unwrap_or(type_string), - &step_string[brace_index..], + "[TIMING:end] {} -- {}.{:03}", + pretty_print_step(&step), dur.as_secs(), dur.subsec_millis() ); @@ -1804,6 +1805,17 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s } } +fn pretty_print_step(step: &S) -> String { + let step_dbg_repr = format!("{step:?}"); + let brace_index = step_dbg_repr.find('{').unwrap_or(0); + + // Normalize step type path to only keep the module and the type name + let path = type_name::().rsplit("::").take(2).collect::>(); + let type_string = path.into_iter().rev().collect::>().join("::"); + + format!("{type_string} {}", &step_dbg_repr[brace_index..]) +} + impl<'a> AsRef for Builder<'a> { fn as_ref(&self) -> &ExecutionContext { self.exec_ctx() From c846f7c8bfc202ae86ce667a4c7e10f57ff9c89d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 10:15:53 +0200 Subject: [PATCH 06/18] Replace `tracing_forest` with custom span formatting --- src/bootstrap/Cargo.lock | 188 ++++++++++++++++++++++++++------- src/bootstrap/Cargo.toml | 4 +- src/bootstrap/src/bin/main.rs | 190 +++++++++++++++++++++++++++++++++- 3 files changed, 338 insertions(+), 44 deletions(-) diff --git a/src/bootstrap/Cargo.lock b/src/bootstrap/Cargo.lock index e091c94eb53aa..f5d04c39d3f33 100644 --- a/src/bootstrap/Cargo.lock +++ b/src/bootstrap/Cargo.lock @@ -12,12 +12,18 @@ dependencies = [ ] [[package]] -name = "ansi_term" -version = "0.12.1" +name = "android-tzdata" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e999941b234f3131b00bc13c22d06e8c5ff726d1b6318ac7eb276997bbb4fef0" + +[[package]] +name = "android_system_properties" +version = "0.1.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2" +checksum = "819e7219dbd41043ac279b19830f2efc897156490d7fd6ea916720117ee66311" dependencies = [ - "winapi", + "libc", ] [[package]] @@ -26,6 +32,12 @@ version = "1.0.10" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "55cc3b69f167a1ef2e161439aa98aed94e6028e5f9a59be9a6ffb47aef1651f9" +[[package]] +name = "autocfg" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c08606f8c3cbf4ce6ec8e28fb0014a2c086708fe954eaa885384a6165172e7e8" + [[package]] name = "bitflags" version = "2.6.0" @@ -47,6 +59,7 @@ version = "0.0.0" dependencies = [ "build_helper", "cc", + "chrono", "clap", "clap_complete", "cmake", @@ -71,7 +84,6 @@ dependencies = [ "toml", "tracing", "tracing-chrome", - "tracing-forest", "tracing-subscriber", "walkdir", "windows", @@ -97,6 +109,12 @@ dependencies = [ "serde_derive", ] +[[package]] +name = "bumpalo" +version = "3.19.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "46c5e41b57b8bba42a04676d81cb89e9ee8e859a1a66f80a5a72e1cb76b34d43" + [[package]] name = "cc" version = "1.2.23" @@ -112,6 +130,20 @@ version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "baf1de4339761588bc0619e3cbc0120ee582ebb74b53b4efbf79117bd2da40fd" +[[package]] +name = "chrono" +version = "0.4.41" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c469d952047f47f91b68d1cba3f10d63c11d73e4636f24f08daf0278abf01c4d" +dependencies = [ + "android-tzdata", + "iana-time-zone", + "js-sys", + "num-traits", + "wasm-bindgen", + "windows-link", +] + [[package]] name = "clap" version = "4.5.20" @@ -180,6 +212,12 @@ dependencies = [ "windows-sys 0.59.0", ] +[[package]] +name = "core-foundation-sys" +version = "0.8.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "773648b94d0e5d620f64f280777445740e61fe701025087ec8b57f45c791888b" + [[package]] name = "cpufeatures" version = "0.2.15" @@ -335,6 +373,30 @@ dependencies = [ "windows-sys 0.52.0", ] +[[package]] +name = "iana-time-zone" +version = "0.1.63" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b0c919e5debc312ad217002b8048a17b7d83f80703865bbfcfebb0458b0b27d8" +dependencies = [ + "android_system_properties", + "core-foundation-sys", + "iana-time-zone-haiku", + "js-sys", + "log", + "wasm-bindgen", + "windows-core", +] + +[[package]] +name = "iana-time-zone-haiku" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f31827a206f56af32e590ba56d5d2d085f558508192593743f16b2306495269f" +dependencies = [ + "cc", +] + [[package]] name = "ignore" version = "0.4.23" @@ -368,6 +430,16 @@ version = "1.0.11" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49f1f14873335454500d59611f1cf4a4b0f786f9ac11f4312a78e4cf2566695b" +[[package]] +name = "js-sys" +version = "0.3.77" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1cfaf33c695fc6e08064efbc1f72ec937429614f25eef83af942d0e227c3a28f" +dependencies = [ + "once_cell", + "wasm-bindgen", +] + [[package]] name = "junction" version = "1.2.0" @@ -458,6 +530,15 @@ dependencies = [ "winapi", ] +[[package]] +name = "num-traits" +version = "0.2.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "071dfc062690e90b734c0b2273ce72ad0ffa95f0c74596bc250dcfd960262841" +dependencies = [ + "autocfg", +] + [[package]] name = "objc2-core-foundation" version = "0.3.1" @@ -620,6 +701,12 @@ dependencies = [ "windows-sys 0.59.0", ] +[[package]] +name = "rustversion" +version = "1.0.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b39cdef0fa800fc44525c84ccb54a029961a8215f9619753635a9c0d2538d46d" + [[package]] name = "ryu" version = "1.0.18" @@ -775,26 +862,6 @@ dependencies = [ "winapi-util", ] -[[package]] -name = "thiserror" -version = "1.0.69" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b6aaf5339b578ea85b50e080feb250a3e8ae8cfcdff9a461c9ec2904bc923f52" -dependencies = [ - "thiserror-impl", -] - -[[package]] -name = "thiserror-impl" -version = "1.0.69" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4fee6c4efc90059e10f81e6d42c60a18f76588c3d74cb83a0b242a2b6c7504c1" -dependencies = [ - "proc-macro2", - "quote", - "syn", -] - [[package]] name = "thread_local" version = "1.1.8" @@ -857,19 +924,6 @@ dependencies = [ "valuable", ] -[[package]] -name = "tracing-forest" -version = "0.1.6" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ee40835db14ddd1e3ba414292272eddde9dad04d3d4b65509656414d1c42592f" -dependencies = [ - "ansi_term", - "smallvec", - "thiserror", - "tracing", - "tracing-subscriber", -] - [[package]] name = "tracing-log" version = "0.2.0" @@ -942,6 +996,64 @@ dependencies = [ "wit-bindgen-rt", ] +[[package]] +name = "wasm-bindgen" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1edc8929d7499fc4e8f0be2262a241556cfc54a0bea223790e71446f2aab1ef5" +dependencies = [ + "cfg-if", + "once_cell", + "rustversion", + "wasm-bindgen-macro", +] + +[[package]] +name = "wasm-bindgen-backend" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2f0a0651a5c2bc21487bde11ee802ccaf4c51935d0d3d42a6101f98161700bc6" +dependencies = [ + "bumpalo", + "log", + "proc-macro2", + "quote", + "syn", + "wasm-bindgen-shared", +] + +[[package]] +name = "wasm-bindgen-macro" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7fe63fc6d09ed3792bd0897b314f53de8e16568c2b3f7982f468c0bf9bd0b407" +dependencies = [ + "quote", + "wasm-bindgen-macro-support", +] + +[[package]] +name = "wasm-bindgen-macro-support" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8ae87ea40c9f689fc23f209965b6fb8a99ad69aeeb0231408be24920604395de" +dependencies = [ + "proc-macro2", + "quote", + "syn", + "wasm-bindgen-backend", + "wasm-bindgen-shared", +] + +[[package]] +name = "wasm-bindgen-shared" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1a05d73b933a847d6cccdda8f838a22ff101ad9bf93e33684f39c1f5f0eece3d" +dependencies = [ + "unicode-ident", +] + [[package]] name = "winapi" version = "0.3.9" diff --git a/src/bootstrap/Cargo.toml b/src/bootstrap/Cargo.toml index ecb332eb7e3ad..ae5a5d798e57c 100644 --- a/src/bootstrap/Cargo.toml +++ b/src/bootstrap/Cargo.toml @@ -7,7 +7,7 @@ default-run = "bootstrap" [features] build-metrics = ["sysinfo"] -tracing = ["dep:tracing", "dep:tracing-chrome", "dep:tracing-subscriber", "dep:tracing-forest", "dep:tempfile"] +tracing = ["dep:tracing", "dep:tracing-chrome", "dep:tracing-subscriber", "dep:chrono", "dep:tempfile"] [lib] path = "src/lib.rs" @@ -61,10 +61,10 @@ xz2 = "0.1" sysinfo = { version = "0.36.0", default-features = false, optional = true, features = ["system"] } # Dependencies needed by the `tracing` feature +chrono = { version = "0.4", optional = true } tracing = { version = "0.1", optional = true, features = ["attributes"] } tracing-chrome = { version = "0.7", optional = true } tracing-subscriber = { version = "0.3", optional = true, features = ["env-filter", "fmt", "registry", "std"] } -tracing-forest = { version = "0.1.6", optional = true, default-features = false, features = ["smallvec", "ansi", "env-filter"] } tempfile = { version = "3.15.0", optional = true } [target.'cfg(windows)'.dependencies.junction] diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index a078a519b85cd..a98fc447e89da 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -263,16 +263,198 @@ fn check_version(config: &Config) -> Option { // "tracing", instrument(..))]`. #[cfg(feature = "tracing")] fn setup_tracing(profiling_enabled: bool) -> Option { + use std::fmt::Debug; use std::fs::File; use std::io::BufWriter; + use std::sync::atomic::{AtomicU32, Ordering}; - use tracing_forest::ForestLayer; - use tracing_subscriber::EnvFilter; - use tracing_subscriber::layer::SubscriberExt; + use chrono::{DateTime, Utc}; + use tracing::field::{Field, Visit}; + use tracing::{Event, Id, Level, Subscriber}; + use tracing_subscriber::layer::{Context, SubscriberExt}; + use tracing_subscriber::registry::{LookupSpan, SpanRef}; + use tracing_subscriber::{EnvFilter, Layer}; let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); - let registry = tracing_subscriber::registry().with(filter).with(ForestLayer::default()); + #[derive(Default)] + struct FieldValues { + message: Option, + fields: Vec<(&'static str, String)>, + } + + impl Visit for FieldValues { + fn record_debug(&mut self, field: &Field, value: &dyn Debug) { + if field.name() == "message" { + self.message = Some(format!("{value:?}")); + } else { + self.fields.push((field.name(), format!("{value:?}"))); + } + } + } + + #[derive(Copy, Clone)] + enum SpanAction { + Enter, + } + + #[derive(Default)] + struct TracingPrinter { + indent: AtomicU32, + span_values: std::sync::Mutex>, + } + + impl TracingPrinter { + fn format_header( + &self, + writer: &mut W, + time: DateTime, + level: &Level, + ) -> std::io::Result<()> { + // Use a fixed-width timestamp without date, that shouldn't be very important + let timestamp = time.format("%H:%M:%S.%3f"); + write!(writer, "{timestamp} ")?; + // Make sure that levels are aligned to the same number of characters, in order not to + // break the layout + write!(writer, "{level:>5} ")?; + write!(writer, "{}", " ".repeat(self.indent.load(Ordering::Relaxed) as usize)) + } + + fn write_event(&self, writer: &mut W, event: &Event<'_>) -> std::io::Result<()> { + let now = Utc::now(); + + self.format_header(writer, now, event.metadata().level())?; + + let mut field_values = FieldValues::default(); + event.record(&mut field_values); + + if let Some(msg) = &field_values.message { + write!(writer, "{msg}")?; + } + + if !field_values.fields.is_empty() { + if field_values.message.is_some() { + write!(writer, " ")?; + } + write!(writer, "[")?; + for (index, (name, value)) in field_values.fields.iter().enumerate() { + write!(writer, "{name} = {value}")?; + if index < field_values.fields.len() - 1 { + write!(writer, ", ")?; + } + } + write!(writer, "]")?; + } + write_location(writer, event.metadata())?; + writeln!(writer)?; + Ok(()) + } + + fn write_span( + &self, + writer: &mut W, + span: SpanRef<'_, S>, + field_values: Option<&FieldValues>, + action: SpanAction, + ) -> std::io::Result<()> + where + S: for<'lookup> LookupSpan<'lookup>, + { + let now = Utc::now(); + + self.format_header(writer, now, span.metadata().level())?; + match action { + SpanAction::Enter => { + write!(writer, "> ")?; + } + } + + write!(writer, "{}", span.name())?; + if let Some(values) = field_values.filter(|v| !v.fields.is_empty()) { + write!(writer, " [")?; + for (index, (name, value)) in values.fields.iter().enumerate() { + write!(writer, "{name} = {value}")?; + if index < values.fields.len() - 1 { + write!(writer, ", ")?; + } + } + write!(writer, "]")?; + } + + write_location(writer, span.metadata())?; + writeln!(writer)?; + Ok(()) + } + } + + fn write_location( + writer: &mut W, + metadata: &'static tracing::Metadata<'static>, + ) -> std::io::Result<()> { + use std::path::{Path, PathBuf}; + + if let Some(filename) = metadata.file() { + // Keep only the module name and file name to make it shorter + let filename: PathBuf = Path::new(filename) + .components() + // Take last two path components + .rev() + .take(2) + .collect::>() + .into_iter() + .rev() + .collect(); + + write!(writer, " ({}", filename.display())?; + if let Some(line) = metadata.line() { + write!(writer, ":{line}")?; + } + write!(writer, ")")?; + } + Ok(()) + } + + impl Layer for TracingPrinter + where + S: Subscriber, + S: for<'lookup> LookupSpan<'lookup>, + { + fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) { + let mut writer = std::io::stderr().lock(); + self.write_event(&mut writer, event).unwrap(); + } + + fn on_new_span( + &self, + attrs: &tracing::span::Attributes<'_>, + id: &Id, + _ctx: Context<'_, S>, + ) { + // Record value of span fields + // Note that we do not implement changing values of span fields after they are created. + // For that we would also need to implement the `on_record` method + + let mut field_values = FieldValues::default(); + attrs.record(&mut field_values); + self.span_values.lock().unwrap().insert(id.clone(), field_values); + } + + fn on_enter(&self, id: &Id, ctx: Context<'_, S>) { + if let Some(span) = ctx.span(id) { + let mut writer = std::io::stderr().lock(); + let values = self.span_values.lock().unwrap(); + let values = values.get(id); + self.write_span(&mut writer, span, values, SpanAction::Enter).unwrap(); + } + self.indent.fetch_add(1, Ordering::Relaxed); + } + + fn on_exit(&self, _id: &Id, _ctx: Context<'_, S>) { + self.indent.fetch_sub(1, Ordering::Relaxed); + } + } + + let registry = tracing_subscriber::registry().with(filter).with(TracingPrinter::default()); let guard = if profiling_enabled { // When we're creating this layer, we do not yet know the location of the tracing output From 1e14229e40aae28390d11f8de8997771614c68dd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 16:56:47 +0200 Subject: [PATCH 07/18] Create a span for each executed step --- src/bootstrap/src/bin/main.rs | 97 +++++++++++++++++++++------ src/bootstrap/src/core/builder/mod.rs | 37 ++++++++-- src/bootstrap/src/lib.rs | 2 + 3 files changed, 108 insertions(+), 28 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index a98fc447e89da..bdf85a50afd37 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -268,6 +268,7 @@ fn setup_tracing(profiling_enabled: bool) -> Option { use std::io::BufWriter; use std::sync::atomic::{AtomicU32, Ordering}; + use bootstrap::STEP_NAME_TARGET; use chrono::{DateTime, Utc}; use tracing::field::{Field, Visit}; use tracing::{Event, Id, Level, Subscriber}; @@ -277,18 +278,40 @@ fn setup_tracing(profiling_enabled: bool) -> Option { let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); + /// Visitor that extracts both known and unknown field values from events and spans. #[derive(Default)] struct FieldValues { + /// Main event message message: Option, + /// Name of a recorded psna + step_name: Option, + /// The rest of arbitrary event/span fields fields: Vec<(&'static str, String)>, } impl Visit for FieldValues { + /// Record fields if possible using `record_str`, to avoid rendering simple strings with + /// their `Debug` representation, which adds extra quotes. + fn record_str(&mut self, field: &Field, value: &str) { + match field.name() { + "step_name" => { + self.step_name = Some(value.to_string()); + } + name => { + self.fields.push((name, value.to_string())); + } + } + } + fn record_debug(&mut self, field: &Field, value: &dyn Debug) { - if field.name() == "message" { - self.message = Some(format!("{value:?}")); - } else { - self.fields.push((field.name(), format!("{value:?}"))); + let formatted = format!("{value:?}"); + match field.name() { + "message" => { + self.message = Some(formatted); + } + name => { + self.fields.push((name, formatted)); + } } } } @@ -298,6 +321,9 @@ fn setup_tracing(profiling_enabled: bool) -> Option { Enter, } + /// Holds the name of a step, stored in `tracing_subscriber`'s extensions. + struct StepNameExtension(String); + #[derive(Default)] struct TracingPrinter { indent: AtomicU32, @@ -369,17 +395,31 @@ fn setup_tracing(profiling_enabled: bool) -> Option { } } - write!(writer, "{}", span.name())?; - if let Some(values) = field_values.filter(|v| !v.fields.is_empty()) { - write!(writer, " [")?; - for (index, (name, value)) in values.fields.iter().enumerate() { - write!(writer, "{name} = {value}")?; - if index < values.fields.len() - 1 { - write!(writer, ", ")?; + // We handle steps specially. We instrument them dynamically in `Builder::ensure`, + // and we want to have custom name for each step span. But tracing doesn't allow setting + // dynamic span names. So we detect step spans here and override their name. + if span.metadata().target() == STEP_NAME_TARGET { + let name = field_values.and_then(|v| v.step_name.as_deref()).unwrap_or(span.name()); + write!(writer, "{name}")?; + + // There should be only one more field called `args` + if let Some(values) = field_values { + let field = &values.fields[0]; + write!(writer, " {{{}}}", field.1)?; + } + } else { + write!(writer, "{}", span.name())?; + if let Some(values) = field_values.filter(|v| !v.fields.is_empty()) { + write!(writer, " [")?; + for (index, (name, value)) in values.fields.iter().enumerate() { + write!(writer, "{name} = {value}")?; + if index < values.fields.len() - 1 { + write!(writer, ", ")?; + } } + write!(writer, "]")?; } - write!(writer, "]")?; - } + }; write_location(writer, span.metadata())?; writeln!(writer)?; @@ -424,18 +464,18 @@ fn setup_tracing(profiling_enabled: bool) -> Option { self.write_event(&mut writer, event).unwrap(); } - fn on_new_span( - &self, - attrs: &tracing::span::Attributes<'_>, - id: &Id, - _ctx: Context<'_, S>, - ) { + fn on_new_span(&self, attrs: &tracing::span::Attributes<'_>, id: &Id, ctx: Context<'_, S>) { // Record value of span fields // Note that we do not implement changing values of span fields after they are created. // For that we would also need to implement the `on_record` method - let mut field_values = FieldValues::default(); attrs.record(&mut field_values); + + // We need to propagate the actual name of the span to the Chrome layer below, because + // it cannot access field values. We do that through extensions. + if let Some(step_name) = field_values.step_name.clone() { + ctx.span(id).unwrap().extensions_mut().insert(StepNameExtension(step_name)); + } self.span_values.lock().unwrap().insert(id.clone(), field_values); } @@ -466,8 +506,21 @@ fn setup_tracing(profiling_enabled: bool) -> Option { let chrome_tracing_path = tempdir.path().join("bootstrap-trace.json"); let file = BufWriter::new(File::create(&chrome_tracing_path).unwrap()); - let chrome_layer = - tracing_chrome::ChromeLayerBuilder::new().writer(file).include_args(true); + let chrome_layer = tracing_chrome::ChromeLayerBuilder::new() + .writer(file) + .include_args(true) + .name_fn(Box::new(|event_or_span| match event_or_span { + tracing_chrome::EventOrSpan::Event(e) => e.metadata().name().to_string(), + tracing_chrome::EventOrSpan::Span(s) => { + if s.metadata().target() == STEP_NAME_TARGET + && let Some(extension) = s.extensions().get::() + { + extension.0.clone() + } else { + s.metadata().name().to_string() + } + } + })); let (chrome_layer, guard) = chrome_layer.build(); tracing::subscriber::set_global_default(registry.with(chrome_layer)).unwrap(); diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs index fc454ebe81971..0eae2f58a68c2 100644 --- a/src/bootstrap/src/core/builder/mod.rs +++ b/src/bootstrap/src/core/builder/mod.rs @@ -947,6 +947,9 @@ impl Step for Libdir { } } +#[cfg(feature = "tracing")] +pub const STEP_NAME_TARGET: &str = "STEP"; + impl<'a> Builder<'a> { fn get_step_descriptions(kind: Kind) -> Vec { macro_rules! describe { @@ -1709,6 +1712,20 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s let zero = Duration::new(0, 0); let parent = self.time_spent_on_dependencies.replace(zero); + #[cfg(feature = "tracing")] + let _span = { + // Keep the target and field names synchronized with `setup_tracing`. + let span = tracing::info_span!( + target: STEP_NAME_TARGET, + // We cannot use a dynamic name here, so instead we record the actual step name + // in the step_name field. + "step", + step_name = step_name::(), + args = step_debug_args(&step) + ); + span.entered() + }; + let out = step.clone().run(self); let dur = start.elapsed(); let deps = self.time_spent_on_dependencies.replace(parent + dur); @@ -1805,15 +1822,23 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s } } -fn pretty_print_step(step: &S) -> String { - let step_dbg_repr = format!("{step:?}"); - let brace_index = step_dbg_repr.find('{').unwrap_or(0); - +/// Return qualified step name, e.g. `compile::Rustc`. +fn step_name() -> String { // Normalize step type path to only keep the module and the type name let path = type_name::().rsplit("::").take(2).collect::>(); - let type_string = path.into_iter().rev().collect::>().join("::"); + path.into_iter().rev().collect::>().join("::") +} + +/// Renders `step` using its `Debug` implementation and extract the field arguments out of it. +fn step_debug_args(step: &S) -> String { + let step_dbg_repr = format!("{step:?}"); + let brace_start = step_dbg_repr.find('{').unwrap_or(0); + let brace_end = step_dbg_repr.rfind('}').unwrap_or(step_dbg_repr.len()); + step_dbg_repr[brace_start + 1..brace_end - 1].trim().to_string() +} - format!("{type_string} {}", &step_dbg_repr[brace_index..]) +fn pretty_print_step(step: &S) -> String { + format!("{} {{ {} }}", step_name::(), step_debug_args(step)) } impl<'a> AsRef for Builder<'a> { diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs index 7d6c0658f4754..d980c91d8ebdb 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -43,6 +43,8 @@ mod core; mod utils; pub use core::builder::PathSet; +#[cfg(feature = "tracing")] +pub use core::builder::STEP_NAME_TARGET; pub use core::config::flags::{Flags, Subcommand}; pub use core::config::{ChangeId, Config}; From 690c781475acb890f33d928186bdaea9ef179330 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 16:57:31 +0200 Subject: [PATCH 08/18] Remove ad-hoc print of executed/cached steps in verbose mode When verbose mode is enabled, it is very hard to see the actually executed steps. --- src/bootstrap/src/core/builder/mod.rs | 4 ---- 1 file changed, 4 deletions(-) diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs index 0eae2f58a68c2..4ac040ad0ad63 100644 --- a/src/bootstrap/src/core/builder/mod.rs +++ b/src/bootstrap/src/core/builder/mod.rs @@ -1677,8 +1677,6 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s panic!("{}", out); } if let Some(out) = self.cache.get(&step) { - self.verbose_than(1, || println!("{}c {:?}", " ".repeat(stack.len()), step)); - #[cfg(feature = "tracing")] { if let Some(parent) = stack.last() { @@ -1688,7 +1686,6 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s } return out; } - self.verbose_than(1, || println!("{}> {:?}", " ".repeat(stack.len()), step)); #[cfg(feature = "tracing")] { @@ -1749,7 +1746,6 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s let cur_step = stack.pop().expect("step stack empty"); assert_eq!(cur_step.downcast_ref(), Some(&step)); } - self.verbose_than(1, || println!("{}< {:?}", " ".repeat(self.stack.borrow().len()), step)); self.cache.put(step, out.clone()); out } From d4039349d1c116d386e1acb8695bacc482d8688d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 17:00:31 +0200 Subject: [PATCH 09/18] Remove manual `#[instrument]` annotations on steps They could easily get out of sync and miss some fields. Now all steps are instrumented automatically. --- src/bootstrap/src/bin/main.rs | 3 - src/bootstrap/src/core/build_steps/compile.rs | 100 +----------------- src/bootstrap/src/core/build_steps/llvm.rs | 20 ---- src/bootstrap/src/core/build_steps/test.rs | 6 -- src/bootstrap/src/core/build_steps/tool.rs | 33 ------ 5 files changed, 1 insertion(+), 161 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index bdf85a50afd37..aa062e14202b5 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -15,8 +15,6 @@ use bootstrap::{ Build, CONFIG_CHANGE_HISTORY, ChangeId, Config, Flags, Subcommand, debug, find_recent_config_change_ids, human_readable_changes, symlink_dir, t, }; -#[cfg(feature = "tracing")] -use tracing::instrument; fn is_profiling_enabled() -> bool { env::var("BOOTSTRAP_PROFILE").is_ok_and(|v| v == "1") @@ -26,7 +24,6 @@ fn is_tracing_enabled() -> bool { is_profiling_enabled() || cfg!(feature = "tracing") } -#[cfg_attr(feature = "tracing", instrument(level = "trace", name = "main"))] fn main() { #[cfg(feature = "tracing")] let guard = setup_tracing(is_profiling_enabled()); diff --git a/src/bootstrap/src/core/build_steps/compile.rs b/src/bootstrap/src/core/build_steps/compile.rs index 79174eb281f65..d20b12b256e70 100644 --- a/src/bootstrap/src/core/build_steps/compile.rs +++ b/src/bootstrap/src/core/build_steps/compile.rs @@ -16,7 +16,7 @@ use std::{env, fs, str}; use serde_derive::Deserialize; #[cfg(feature = "tracing")] -use tracing::{instrument, span}; +use tracing::span; use crate::core::build_steps::gcc::{Gcc, add_cg_gcc_cargo_flags}; use crate::core::build_steps::tool::{RustcPrivateCompilers, SourceType, copy_lld_artifacts}; @@ -104,7 +104,6 @@ impl Step for Std { run.crate_or_deps("sysroot").path("library") } - #[cfg_attr(feature = "tracing", instrument(level = "trace", name = "Std::make_run", skip_all))] fn make_run(run: RunConfig<'_>) { let crates = std_crates_for_run_make(&run); let builder = run.builder; @@ -135,19 +134,6 @@ impl Step for Std { /// This will build the standard library for a particular stage of the build /// using the `compiler` targeting the `target` architecture. The artifacts /// created will also be linked into the sysroot directory. - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "Std::run", - skip_all, - fields( - target = ?self.target, - compiler = ?self.compiler, - force_recompile = self.force_recompile - ), - ), - )] fn run(self, builder: &Builder<'_>) { let target = self.target; @@ -711,19 +697,6 @@ impl Step for StdLink { /// Note that this assumes that `compiler` has already generated the libstd /// libraries for `target`, and this method will find them in the relevant /// output directory. - #[cfg_attr( - feature = "tracing", - instrument( - level = "trace", - name = "StdLink::run", - skip_all, - fields( - compiler = ?self.compiler, - target_compiler = ?self.target_compiler, - target = ?self.target - ), - ), - )] fn run(self, builder: &Builder<'_>) { let compiler = self.compiler; let target_compiler = self.target_compiler; @@ -889,15 +862,6 @@ impl Step for StartupObjects { /// They don't require any library support as they're just plain old object /// files, so we just use the nightly snapshot compiler to always build them (as /// no other compilers are guaranteed to be available). - #[cfg_attr( - feature = "tracing", - instrument( - level = "trace", - name = "StartupObjects::run", - skip_all, - fields(compiler = ?self.compiler, target = ?self.target), - ), - )] fn run(self, builder: &Builder<'_>) -> Vec<(PathBuf, DependencyType)> { let for_compiler = self.compiler; let target = self.target; @@ -1027,15 +991,6 @@ impl Step for Rustc { /// This will build the compiler for a particular stage of the build using /// the `build_compiler` targeting the `target` architecture. The artifacts /// created will also be linked into the sysroot directory. - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "Rustc::run", - skip_all, - fields(previous_compiler = ?self.build_compiler, target = ?self.target), - ), - )] fn run(self, builder: &Builder<'_>) -> u32 { let build_compiler = self.build_compiler; let target = self.target; @@ -1511,19 +1466,6 @@ impl Step for RustcLink { } /// Same as `std_link`, only for librustc - #[cfg_attr( - feature = "tracing", - instrument( - level = "trace", - name = "RustcLink::run", - skip_all, - fields( - compiler = ?self.compiler, - previous_stage_compiler = ?self.previous_stage_compiler, - target = ?self.target, - ), - ), - )] fn run(self, builder: &Builder<'_>) { let compiler = self.compiler; let previous_stage_compiler = self.previous_stage_compiler; @@ -1556,17 +1498,6 @@ impl Step for GccCodegenBackend { }); } - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "GccCodegenBackend::run", - skip_all, - fields( - compilers = ?self.compilers, - ), - ), - )] fn run(self, builder: &Builder<'_>) -> Self::Output { let target = self.compilers.target(); let build_compiler = self.compilers.build_compiler(); @@ -1641,17 +1572,6 @@ impl Step for CraneliftCodegenBackend { }); } - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "CraneliftCodegenBackend::run", - skip_all, - fields( - compilers = ?self.compilers, - ), - ), - )] fn run(self, builder: &Builder<'_>) -> Self::Output { let target = self.compilers.target(); let build_compiler = self.compilers.build_compiler(); @@ -1816,15 +1736,6 @@ impl Step for Sysroot { /// Returns the sysroot that `compiler` is supposed to use. /// For the stage0 compiler, this is stage0-sysroot (because of the initial std build). /// For all other stages, it's the same stage directory that the compiler lives in. - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "Sysroot::run", - skip_all, - fields(compiler = ?self.compiler), - ), - )] fn run(self, builder: &Builder<'_>) -> PathBuf { let compiler = self.compiler; let host_dir = builder.out.join(compiler.host); @@ -2000,15 +1911,6 @@ impl Step for Assemble { /// This will assemble a compiler in `build/$host/stage$stage`. The compiler /// must have been previously produced by the `stage - 1` builder.build /// compiler. - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "Assemble::run", - skip_all, - fields(target_compiler = ?self.target_compiler), - ), - )] fn run(self, builder: &Builder<'_>) -> Compiler { let target_compiler = self.target_compiler; diff --git a/src/bootstrap/src/core/build_steps/llvm.rs b/src/bootstrap/src/core/build_steps/llvm.rs index 16941a32bb16e..aab2b634c43be 100644 --- a/src/bootstrap/src/core/build_steps/llvm.rs +++ b/src/bootstrap/src/core/build_steps/llvm.rs @@ -15,8 +15,6 @@ use std::sync::OnceLock; use std::{env, fs}; use build_helper::git::PathFreshness; -#[cfg(feature = "tracing")] -use tracing::instrument; use crate::core::builder::{Builder, RunConfig, ShouldRun, Step, StepMetadata}; use crate::core::config::{Config, TargetSelection}; @@ -266,15 +264,6 @@ impl Step for Llvm { } /// Compile LLVM for `target`. - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "Llvm::run", - skip_all, - fields(target = ?self.target), - ), - )] fn run(self, builder: &Builder<'_>) -> LlvmResult { let target = self.target; let target_native = if self.target.starts_with("riscv") { @@ -919,15 +908,6 @@ impl Step for Enzyme { } /// Compile Enzyme for `target`. - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "Enzyme::run", - skip_all, - fields(target = ?self.target), - ), - )] fn run(self, builder: &Builder<'_>) -> PathBuf { builder.require_submodule( "src/tools/enzyme", diff --git a/src/bootstrap/src/core/build_steps/test.rs b/src/bootstrap/src/core/build_steps/test.rs index 2f933baa4a4cd..2ea4cab20281f 100644 --- a/src/bootstrap/src/core/build_steps/test.rs +++ b/src/bootstrap/src/core/build_steps/test.rs @@ -10,8 +10,6 @@ use std::path::{Path, PathBuf}; use std::{env, fs, iter}; use build_helper::exit; -#[cfg(feature = "tracing")] -use tracing::instrument; use crate::core::build_steps::compile::{Std, run_cargo}; use crate::core::build_steps::doc::DocumentationFormat; @@ -760,10 +758,6 @@ impl Step for CompiletestTest { } /// Runs `cargo test` for compiletest. - #[cfg_attr( - feature = "tracing", - instrument(level = "debug", name = "CompiletestTest::run", skip_all) - )] fn run(self, builder: &Builder<'_>) { let host = self.host; diff --git a/src/bootstrap/src/core/build_steps/tool.rs b/src/bootstrap/src/core/build_steps/tool.rs index aa00cd03c5bb7..a5ebe9a79f9ba 100644 --- a/src/bootstrap/src/core/build_steps/tool.rs +++ b/src/bootstrap/src/core/build_steps/tool.rs @@ -13,9 +13,6 @@ use std::ffi::OsStr; use std::path::PathBuf; use std::{env, fs}; -#[cfg(feature = "tracing")] -use tracing::instrument; - use crate::core::build_steps::compile::is_lto_stage; use crate::core::build_steps::toolstate::ToolState; use crate::core::build_steps::{compile, llvm}; @@ -443,14 +440,6 @@ macro_rules! bootstrap_tool { }); } - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = $tool_name, - skip_all, - ), - )] fn run(self, builder: &Builder<'_>) -> ToolBuildResult { $( for submodule in $submodules { @@ -927,15 +916,6 @@ impl Step for LldWrapper { }); } - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "LldWrapper::run", - skip_all, - fields(build_compiler = ?self.build_compiler), - ), - )] fn run(self, builder: &Builder<'_>) -> Self::Output { let lld_dir = builder.ensure(llvm::Lld { target: self.target }); let tool = builder.ensure(ToolBuild { @@ -1028,15 +1008,6 @@ impl Step for WasmComponentLd { }); } - #[cfg_attr( - feature = "tracing", - instrument( - level = "debug", - name = "WasmComponentLd::run", - skip_all, - fields(build_compiler = ?self.build_compiler), - ), - )] fn run(self, builder: &Builder<'_>) -> ToolBuildResult { builder.ensure(ToolBuild { build_compiler: self.build_compiler, @@ -1233,10 +1204,6 @@ impl Step for LlvmBitcodeLinker { }); } - #[cfg_attr( - feature = "tracing", - instrument(level = "debug", name = "LlvmBitcodeLinker::run", skip_all) - )] fn run(self, builder: &Builder<'_>) -> ToolBuildResult { builder.ensure(ToolBuild { build_compiler: self.build_compiler, From 604c180bf583822d34a25c935779bbea12c5003e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 17:18:21 +0200 Subject: [PATCH 10/18] Move tracing setup to the `tracing` module --- src/bootstrap/src/bin/main.rs | 299 +--------------------------- src/bootstrap/src/lib.rs | 2 + src/bootstrap/src/utils/tracing.rs | 301 +++++++++++++++++++++++++++++ 3 files changed, 304 insertions(+), 298 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index aa062e14202b5..0dc3cad0cd8f5 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -26,7 +26,7 @@ fn is_tracing_enabled() -> bool { fn main() { #[cfg(feature = "tracing")] - let guard = setup_tracing(is_profiling_enabled()); + let guard = bootstrap::setup_tracing(is_profiling_enabled()); let start_time = Instant::now(); @@ -247,300 +247,3 @@ fn check_version(config: &Config) -> Option { Some(msg) } - -// # Note on `tracing` usage in bootstrap -// -// Due to the conditional compilation via the `tracing` cargo feature, this means that `tracing` -// usages in bootstrap need to be also gated behind the `tracing` feature: -// -// - `tracing` macros with log levels (`trace!`, `debug!`, `warn!`, `info`, `error`) should not be -// used *directly*. You should use the wrapped `tracing` macros which gate the actual invocations -// behind `feature = "tracing"`. -// - `tracing`'s `#[instrument(..)]` macro will need to be gated like `#![cfg_attr(feature = -// "tracing", instrument(..))]`. -#[cfg(feature = "tracing")] -fn setup_tracing(profiling_enabled: bool) -> Option { - use std::fmt::Debug; - use std::fs::File; - use std::io::BufWriter; - use std::sync::atomic::{AtomicU32, Ordering}; - - use bootstrap::STEP_NAME_TARGET; - use chrono::{DateTime, Utc}; - use tracing::field::{Field, Visit}; - use tracing::{Event, Id, Level, Subscriber}; - use tracing_subscriber::layer::{Context, SubscriberExt}; - use tracing_subscriber::registry::{LookupSpan, SpanRef}; - use tracing_subscriber::{EnvFilter, Layer}; - - let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); - - /// Visitor that extracts both known and unknown field values from events and spans. - #[derive(Default)] - struct FieldValues { - /// Main event message - message: Option, - /// Name of a recorded psna - step_name: Option, - /// The rest of arbitrary event/span fields - fields: Vec<(&'static str, String)>, - } - - impl Visit for FieldValues { - /// Record fields if possible using `record_str`, to avoid rendering simple strings with - /// their `Debug` representation, which adds extra quotes. - fn record_str(&mut self, field: &Field, value: &str) { - match field.name() { - "step_name" => { - self.step_name = Some(value.to_string()); - } - name => { - self.fields.push((name, value.to_string())); - } - } - } - - fn record_debug(&mut self, field: &Field, value: &dyn Debug) { - let formatted = format!("{value:?}"); - match field.name() { - "message" => { - self.message = Some(formatted); - } - name => { - self.fields.push((name, formatted)); - } - } - } - } - - #[derive(Copy, Clone)] - enum SpanAction { - Enter, - } - - /// Holds the name of a step, stored in `tracing_subscriber`'s extensions. - struct StepNameExtension(String); - - #[derive(Default)] - struct TracingPrinter { - indent: AtomicU32, - span_values: std::sync::Mutex>, - } - - impl TracingPrinter { - fn format_header( - &self, - writer: &mut W, - time: DateTime, - level: &Level, - ) -> std::io::Result<()> { - // Use a fixed-width timestamp without date, that shouldn't be very important - let timestamp = time.format("%H:%M:%S.%3f"); - write!(writer, "{timestamp} ")?; - // Make sure that levels are aligned to the same number of characters, in order not to - // break the layout - write!(writer, "{level:>5} ")?; - write!(writer, "{}", " ".repeat(self.indent.load(Ordering::Relaxed) as usize)) - } - - fn write_event(&self, writer: &mut W, event: &Event<'_>) -> std::io::Result<()> { - let now = Utc::now(); - - self.format_header(writer, now, event.metadata().level())?; - - let mut field_values = FieldValues::default(); - event.record(&mut field_values); - - if let Some(msg) = &field_values.message { - write!(writer, "{msg}")?; - } - - if !field_values.fields.is_empty() { - if field_values.message.is_some() { - write!(writer, " ")?; - } - write!(writer, "[")?; - for (index, (name, value)) in field_values.fields.iter().enumerate() { - write!(writer, "{name} = {value}")?; - if index < field_values.fields.len() - 1 { - write!(writer, ", ")?; - } - } - write!(writer, "]")?; - } - write_location(writer, event.metadata())?; - writeln!(writer)?; - Ok(()) - } - - fn write_span( - &self, - writer: &mut W, - span: SpanRef<'_, S>, - field_values: Option<&FieldValues>, - action: SpanAction, - ) -> std::io::Result<()> - where - S: for<'lookup> LookupSpan<'lookup>, - { - let now = Utc::now(); - - self.format_header(writer, now, span.metadata().level())?; - match action { - SpanAction::Enter => { - write!(writer, "> ")?; - } - } - - // We handle steps specially. We instrument them dynamically in `Builder::ensure`, - // and we want to have custom name for each step span. But tracing doesn't allow setting - // dynamic span names. So we detect step spans here and override their name. - if span.metadata().target() == STEP_NAME_TARGET { - let name = field_values.and_then(|v| v.step_name.as_deref()).unwrap_or(span.name()); - write!(writer, "{name}")?; - - // There should be only one more field called `args` - if let Some(values) = field_values { - let field = &values.fields[0]; - write!(writer, " {{{}}}", field.1)?; - } - } else { - write!(writer, "{}", span.name())?; - if let Some(values) = field_values.filter(|v| !v.fields.is_empty()) { - write!(writer, " [")?; - for (index, (name, value)) in values.fields.iter().enumerate() { - write!(writer, "{name} = {value}")?; - if index < values.fields.len() - 1 { - write!(writer, ", ")?; - } - } - write!(writer, "]")?; - } - }; - - write_location(writer, span.metadata())?; - writeln!(writer)?; - Ok(()) - } - } - - fn write_location( - writer: &mut W, - metadata: &'static tracing::Metadata<'static>, - ) -> std::io::Result<()> { - use std::path::{Path, PathBuf}; - - if let Some(filename) = metadata.file() { - // Keep only the module name and file name to make it shorter - let filename: PathBuf = Path::new(filename) - .components() - // Take last two path components - .rev() - .take(2) - .collect::>() - .into_iter() - .rev() - .collect(); - - write!(writer, " ({}", filename.display())?; - if let Some(line) = metadata.line() { - write!(writer, ":{line}")?; - } - write!(writer, ")")?; - } - Ok(()) - } - - impl Layer for TracingPrinter - where - S: Subscriber, - S: for<'lookup> LookupSpan<'lookup>, - { - fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) { - let mut writer = std::io::stderr().lock(); - self.write_event(&mut writer, event).unwrap(); - } - - fn on_new_span(&self, attrs: &tracing::span::Attributes<'_>, id: &Id, ctx: Context<'_, S>) { - // Record value of span fields - // Note that we do not implement changing values of span fields after they are created. - // For that we would also need to implement the `on_record` method - let mut field_values = FieldValues::default(); - attrs.record(&mut field_values); - - // We need to propagate the actual name of the span to the Chrome layer below, because - // it cannot access field values. We do that through extensions. - if let Some(step_name) = field_values.step_name.clone() { - ctx.span(id).unwrap().extensions_mut().insert(StepNameExtension(step_name)); - } - self.span_values.lock().unwrap().insert(id.clone(), field_values); - } - - fn on_enter(&self, id: &Id, ctx: Context<'_, S>) { - if let Some(span) = ctx.span(id) { - let mut writer = std::io::stderr().lock(); - let values = self.span_values.lock().unwrap(); - let values = values.get(id); - self.write_span(&mut writer, span, values, SpanAction::Enter).unwrap(); - } - self.indent.fetch_add(1, Ordering::Relaxed); - } - - fn on_exit(&self, _id: &Id, _ctx: Context<'_, S>) { - self.indent.fetch_sub(1, Ordering::Relaxed); - } - } - - let registry = tracing_subscriber::registry().with(filter).with(TracingPrinter::default()); - - let guard = if profiling_enabled { - // When we're creating this layer, we do not yet know the location of the tracing output - // directory, because it is stored in the output directory determined after Config is parsed, - // but we already want to make tracing calls during (and before) config parsing. - // So we store the output into a temporary file, and then move it to the tracing directory - // before bootstrap ends. - let tempdir = tempfile::TempDir::new().expect("Cannot create temporary directory"); - let chrome_tracing_path = tempdir.path().join("bootstrap-trace.json"); - let file = BufWriter::new(File::create(&chrome_tracing_path).unwrap()); - - let chrome_layer = tracing_chrome::ChromeLayerBuilder::new() - .writer(file) - .include_args(true) - .name_fn(Box::new(|event_or_span| match event_or_span { - tracing_chrome::EventOrSpan::Event(e) => e.metadata().name().to_string(), - tracing_chrome::EventOrSpan::Span(s) => { - if s.metadata().target() == STEP_NAME_TARGET - && let Some(extension) = s.extensions().get::() - { - extension.0.clone() - } else { - s.metadata().name().to_string() - } - } - })); - let (chrome_layer, guard) = chrome_layer.build(); - - tracing::subscriber::set_global_default(registry.with(chrome_layer)).unwrap(); - Some(TracingGuard { guard, _tempdir: tempdir, chrome_tracing_path }) - } else { - tracing::subscriber::set_global_default(registry).unwrap(); - None - }; - - guard -} - -#[cfg(feature = "tracing")] -struct TracingGuard { - guard: tracing_chrome::FlushGuard, - _tempdir: tempfile::TempDir, - chrome_tracing_path: std::path::PathBuf, -} - -#[cfg(feature = "tracing")] -impl TracingGuard { - fn copy_to_dir(self, dir: &std::path::Path) { - drop(self.guard); - std::fs::rename(&self.chrome_tracing_path, dir.join("chrome-trace.json")).unwrap(); - } -} diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs index d980c91d8ebdb..ba3d3fb46e2ee 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -54,6 +54,8 @@ pub use utils::change_tracker::{ CONFIG_CHANGE_HISTORY, find_recent_config_change_ids, human_readable_changes, }; pub use utils::helpers::{PanicTracker, symlink_dir}; +#[cfg(feature = "tracing")] +pub use utils::tracing::setup_tracing; use crate::core::build_steps::vendor::VENDOR_DIR; diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs index 4e596e35060f0..68063131d157a 100644 --- a/src/bootstrap/src/utils/tracing.rs +++ b/src/bootstrap/src/utils/tracing.rs @@ -62,3 +62,304 @@ macro_rules! trace_cmd { } }; } + +// # Note on `tracing` usage in bootstrap +// +// Due to the conditional compilation via the `tracing` cargo feature, this means that `tracing` +// usages in bootstrap need to be also gated behind the `tracing` feature: +// +// - `tracing` macros with log levels (`trace!`, `debug!`, `warn!`, `info`, `error`) should not be +// used *directly*. You should use the wrapped `tracing` macros which gate the actual invocations +// behind `feature = "tracing"`. +// - `tracing`'s `#[instrument(..)]` macro will need to be gated like `#![cfg_attr(feature = +// "tracing", instrument(..))]`. +#[cfg(feature = "tracing")] +mod inner { + use std::fmt::Debug; + use std::fs::File; + use std::io::Write; + use std::sync::atomic::Ordering; + + use chrono::{DateTime, Utc}; + use tracing::field::{Field, Visit}; + use tracing::{Event, Id, Level, Subscriber}; + use tracing_subscriber::layer::{Context, SubscriberExt}; + use tracing_subscriber::registry::{LookupSpan, SpanRef}; + use tracing_subscriber::{EnvFilter, Layer}; + + use crate::STEP_NAME_TARGET; + + pub fn setup_tracing(profiling_enabled: bool) -> Option { + let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); + + let registry = tracing_subscriber::registry().with(filter).with(TracingPrinter::default()); + + let guard = if profiling_enabled { + // When we're creating this layer, we do not yet know the location of the tracing output + // directory, because it is stored in the output directory determined after Config is parsed, + // but we already want to make tracing calls during (and before) config parsing. + // So we store the output into a temporary file, and then move it to the tracing directory + // before bootstrap ends. + let tempdir = tempfile::TempDir::new().expect("Cannot create temporary directory"); + let chrome_tracing_path = tempdir.path().join("bootstrap-trace.json"); + let file = std::io::BufWriter::new(File::create(&chrome_tracing_path).unwrap()); + + let chrome_layer = tracing_chrome::ChromeLayerBuilder::new() + .writer(file) + .include_args(true) + .name_fn(Box::new(|event_or_span| match event_or_span { + tracing_chrome::EventOrSpan::Event(e) => e.metadata().name().to_string(), + tracing_chrome::EventOrSpan::Span(s) => { + if s.metadata().target() == STEP_NAME_TARGET + && let Some(extension) = s.extensions().get::() + { + extension.0.clone() + } else { + s.metadata().name().to_string() + } + } + })); + let (chrome_layer, guard) = chrome_layer.build(); + + tracing::subscriber::set_global_default(registry.with(chrome_layer)).unwrap(); + Some(TracingGuard { guard, _tempdir: tempdir, chrome_tracing_path }) + } else { + tracing::subscriber::set_global_default(registry).unwrap(); + None + }; + + guard + } + + pub struct TracingGuard { + guard: tracing_chrome::FlushGuard, + _tempdir: tempfile::TempDir, + chrome_tracing_path: std::path::PathBuf, + } + + impl TracingGuard { + pub fn copy_to_dir(self, dir: &std::path::Path) { + drop(self.guard); + std::fs::rename(&self.chrome_tracing_path, dir.join("chrome-trace.json")).unwrap(); + } + } + + /// Visitor that extracts both known and unknown field values from events and spans. + #[derive(Default)] + struct FieldValues { + /// Main event message + message: Option, + /// Name of a recorded psna + step_name: Option, + /// The rest of arbitrary event/span fields + fields: Vec<(&'static str, String)>, + } + + impl Visit for FieldValues { + /// Record fields if possible using `record_str`, to avoid rendering simple strings with + /// their `Debug` representation, which adds extra quotes. + fn record_str(&mut self, field: &Field, value: &str) { + match field.name() { + "step_name" => { + self.step_name = Some(value.to_string()); + } + name => { + self.fields.push((name, value.to_string())); + } + } + } + + fn record_debug(&mut self, field: &Field, value: &dyn Debug) { + let formatted = format!("{value:?}"); + match field.name() { + "message" => { + self.message = Some(formatted); + } + name => { + self.fields.push((name, formatted)); + } + } + } + } + + #[derive(Copy, Clone)] + enum SpanAction { + Enter, + } + + /// Holds the name of a step, stored in `tracing_subscriber`'s extensions. + struct StepNameExtension(String); + + #[derive(Default)] + struct TracingPrinter { + indent: std::sync::atomic::AtomicU32, + span_values: std::sync::Mutex>, + } + + impl TracingPrinter { + fn format_header( + &self, + writer: &mut W, + time: DateTime, + level: &Level, + ) -> std::io::Result<()> { + // Use a fixed-width timestamp without date, that shouldn't be very important + let timestamp = time.format("%H:%M:%S.%3f"); + write!(writer, "{timestamp} ")?; + // Make sure that levels are aligned to the same number of characters, in order not to + // break the layout + write!(writer, "{level:>5} ")?; + write!(writer, "{}", " ".repeat(self.indent.load(Ordering::Relaxed) as usize)) + } + + fn write_event(&self, writer: &mut W, event: &Event<'_>) -> std::io::Result<()> { + let now = Utc::now(); + + self.format_header(writer, now, event.metadata().level())?; + + let mut field_values = FieldValues::default(); + event.record(&mut field_values); + + if let Some(msg) = &field_values.message { + write!(writer, "{msg}")?; + } + + if !field_values.fields.is_empty() { + if field_values.message.is_some() { + write!(writer, " ")?; + } + write!(writer, "[")?; + for (index, (name, value)) in field_values.fields.iter().enumerate() { + write!(writer, "{name} = {value}")?; + if index < field_values.fields.len() - 1 { + write!(writer, ", ")?; + } + } + write!(writer, "]")?; + } + write_location(writer, event.metadata())?; + writeln!(writer)?; + Ok(()) + } + + fn write_span( + &self, + writer: &mut W, + span: SpanRef<'_, S>, + field_values: Option<&FieldValues>, + action: SpanAction, + ) -> std::io::Result<()> + where + S: for<'lookup> LookupSpan<'lookup>, + { + let now = Utc::now(); + + self.format_header(writer, now, span.metadata().level())?; + match action { + SpanAction::Enter => { + write!(writer, "> ")?; + } + } + + // We handle steps specially. We instrument them dynamically in `Builder::ensure`, + // and we want to have custom name for each step span. But tracing doesn't allow setting + // dynamic span names. So we detect step spans here and override their name. + if span.metadata().target() == STEP_NAME_TARGET { + let name = field_values.and_then(|v| v.step_name.as_deref()).unwrap_or(span.name()); + write!(writer, "{name}")?; + + // There should be only one more field called `args` + if let Some(values) = field_values { + let field = &values.fields[0]; + write!(writer, " {{{}}}", field.1)?; + } + } else { + write!(writer, "{}", span.name())?; + if let Some(values) = field_values.filter(|v| !v.fields.is_empty()) { + write!(writer, " [")?; + for (index, (name, value)) in values.fields.iter().enumerate() { + write!(writer, "{name} = {value}")?; + if index < values.fields.len() - 1 { + write!(writer, ", ")?; + } + } + write!(writer, "]")?; + } + }; + + write_location(writer, span.metadata())?; + writeln!(writer)?; + Ok(()) + } + } + + fn write_location( + writer: &mut W, + metadata: &'static tracing::Metadata<'static>, + ) -> std::io::Result<()> { + use std::path::{Path, PathBuf}; + + if let Some(filename) = metadata.file() { + // Keep only the module name and file name to make it shorter + let filename: PathBuf = Path::new(filename) + .components() + // Take last two path components + .rev() + .take(2) + .collect::>() + .into_iter() + .rev() + .collect(); + + write!(writer, " ({}", filename.display())?; + if let Some(line) = metadata.line() { + write!(writer, ":{line}")?; + } + write!(writer, ")")?; + } + Ok(()) + } + + impl Layer for TracingPrinter + where + S: Subscriber, + S: for<'lookup> LookupSpan<'lookup>, + { + fn on_new_span(&self, attrs: &tracing::span::Attributes<'_>, id: &Id, ctx: Context<'_, S>) { + // Record value of span fields + // Note that we do not implement changing values of span fields after they are created. + // For that we would also need to implement the `on_record` method + let mut field_values = FieldValues::default(); + attrs.record(&mut field_values); + + // We need to propagate the actual name of the span to the Chrome layer below, because + // it cannot access field values. We do that through extensions. + if let Some(step_name) = field_values.step_name.clone() { + ctx.span(id).unwrap().extensions_mut().insert(StepNameExtension(step_name)); + } + self.span_values.lock().unwrap().insert(id.clone(), field_values); + } + + fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) { + let mut writer = std::io::stderr().lock(); + self.write_event(&mut writer, event).unwrap(); + } + + fn on_enter(&self, id: &Id, ctx: Context<'_, S>) { + if let Some(span) = ctx.span(id) { + let mut writer = std::io::stderr().lock(); + let values = self.span_values.lock().unwrap(); + let values = values.get(id); + self.write_span(&mut writer, span, values, SpanAction::Enter).unwrap(); + } + self.indent.fetch_add(1, Ordering::Relaxed); + } + + fn on_exit(&self, _id: &Id, _ctx: Context<'_, S>) { + self.indent.fetch_sub(1, Ordering::Relaxed); + } + } +} + +#[cfg(feature = "tracing")] +pub use inner::setup_tracing; From c3682b24d792d5348f2c95017a007a619934b521 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 17:30:41 +0200 Subject: [PATCH 11/18] Correctly show executed command name in Chrome trace --- src/bootstrap/src/core/build_steps/compile.rs | 2 +- src/bootstrap/src/core/builder/mod.rs | 4 +- src/bootstrap/src/lib.rs | 2 +- src/bootstrap/src/utils/exec.rs | 16 ++++-- src/bootstrap/src/utils/tracing.rs | 57 +++++++++++++------ 5 files changed, 54 insertions(+), 27 deletions(-) diff --git a/src/bootstrap/src/core/build_steps/compile.rs b/src/bootstrap/src/core/build_steps/compile.rs index d20b12b256e70..d1c8b97d98067 100644 --- a/src/bootstrap/src/core/build_steps/compile.rs +++ b/src/bootstrap/src/core/build_steps/compile.rs @@ -2469,7 +2469,7 @@ pub fn stream_cargo( let mut cmd = cargo.into_cmd(); #[cfg(feature = "tracing")] - let _run_span = crate::trace_cmd!(cmd); + let _run_span = crate::utils::tracing::trace_cmd(&cmd); // Instruct Cargo to give us json messages on stdout, critically leaving // stderr as piped so we can get those pretty colors. diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs index 4ac040ad0ad63..9dab16f5a42a1 100644 --- a/src/bootstrap/src/core/builder/mod.rs +++ b/src/bootstrap/src/core/builder/mod.rs @@ -948,7 +948,7 @@ impl Step for Libdir { } #[cfg(feature = "tracing")] -pub const STEP_NAME_TARGET: &str = "STEP"; +pub const STEP_SPAN_TARGET: &str = "STEP"; impl<'a> Builder<'a> { fn get_step_descriptions(kind: Kind) -> Vec { @@ -1713,7 +1713,7 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s let _span = { // Keep the target and field names synchronized with `setup_tracing`. let span = tracing::info_span!( - target: STEP_NAME_TARGET, + target: STEP_SPAN_TARGET, // We cannot use a dynamic name here, so instead we record the actual step name // in the step_name field. "step", diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs index ba3d3fb46e2ee..6d168693e8f90 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -44,7 +44,7 @@ mod utils; pub use core::builder::PathSet; #[cfg(feature = "tracing")] -pub use core::builder::STEP_NAME_TARGET; +pub use core::builder::STEP_SPAN_TARGET; pub use core::config::flags::{Flags, Subcommand}; pub use core::config::{ChangeId, Config}; diff --git a/src/bootstrap/src/utils/exec.rs b/src/bootstrap/src/utils/exec.rs index ff79a1765526e..ac75e27d57c85 100644 --- a/src/bootstrap/src/utils/exec.rs +++ b/src/bootstrap/src/utils/exec.rs @@ -26,8 +26,6 @@ use build_helper::drop_bomb::DropBomb; use build_helper::exit; use crate::core::config::DryRun; -#[cfg(feature = "tracing")] -use crate::trace_cmd; use crate::{PathBuf, t}; /// What should be done when the command fails. @@ -76,9 +74,17 @@ pub struct CommandFingerprint { } impl CommandFingerprint { + #[cfg(feature = "tracing")] + pub(crate) fn program_name(&self) -> String { + Path::new(&self.program) + .file_name() + .map(|p| p.to_string_lossy().to_string()) + .unwrap_or_else(|| "".to_string()) + } + /// Helper method to format both Command and BootstrapCommand as a short execution line, /// without all the other details (e.g. environment variables). - pub fn format_short_cmd(&self) -> String { + pub(crate) fn format_short_cmd(&self) -> String { use std::fmt::Write; let mut cmd = self.program.to_string_lossy().to_string(); @@ -676,7 +682,7 @@ impl ExecutionContext { let fingerprint = command.fingerprint(); #[cfg(feature = "tracing")] - let span_guard = trace_cmd!(command); + let span_guard = crate::utils::tracing::trace_cmd(command); if let Some(cached_output) = self.command_cache.get(&fingerprint) { command.mark_as_executed(); @@ -768,7 +774,7 @@ impl ExecutionContext { } #[cfg(feature = "tracing")] - let span_guard = trace_cmd!(command); + let span_guard = crate::utils::tracing::trace_cmd(command); let start_time = Instant::now(); let fingerprint = command.fingerprint(); diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs index 68063131d157a..18d19738de96f 100644 --- a/src/bootstrap/src/utils/tracing.rs +++ b/src/bootstrap/src/utils/tracing.rs @@ -48,19 +48,21 @@ macro_rules! error { } } -#[macro_export] -macro_rules! trace_cmd { - ($cmd:expr) => { - { - ::tracing::span!( - target: "COMMAND", - ::tracing::Level::TRACE, - "cmd", - cmd = $cmd.fingerprint().format_short_cmd(), - full_cmd = ?$cmd - ).entered() - } - }; +#[cfg(feature = "tracing")] +const COMMAND_SPAN_TARGET: &str = "COMMAND"; + +#[cfg(feature = "tracing")] +pub fn trace_cmd(command: &crate::BootstrapCommand) -> tracing::span::EnteredSpan { + let fingerprint = command.fingerprint(); + tracing::span!( + target: COMMAND_SPAN_TARGET, + tracing::Level::TRACE, + "cmd", + cmd_name = fingerprint.program_name().to_string(), + cmd = fingerprint.format_short_cmd(), + full_cmd = ?command + ) + .entered() } // # Note on `tracing` usage in bootstrap @@ -87,7 +89,8 @@ mod inner { use tracing_subscriber::registry::{LookupSpan, SpanRef}; use tracing_subscriber::{EnvFilter, Layer}; - use crate::STEP_NAME_TARGET; + use crate::STEP_SPAN_TARGET; + use crate::utils::tracing::COMMAND_SPAN_TARGET; pub fn setup_tracing(profiling_enabled: bool) -> Option { let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); @@ -110,10 +113,14 @@ mod inner { .name_fn(Box::new(|event_or_span| match event_or_span { tracing_chrome::EventOrSpan::Event(e) => e.metadata().name().to_string(), tracing_chrome::EventOrSpan::Span(s) => { - if s.metadata().target() == STEP_NAME_TARGET + if s.metadata().target() == STEP_SPAN_TARGET && let Some(extension) = s.extensions().get::() { extension.0.clone() + } else if s.metadata().target() == COMMAND_SPAN_TARGET + && let Some(extension) = s.extensions().get::() + { + extension.0.clone() } else { s.metadata().name().to_string() } @@ -151,6 +158,8 @@ mod inner { message: Option, /// Name of a recorded psna step_name: Option, + /// Short name of an executed command + cmd_name: Option, /// The rest of arbitrary event/span fields fields: Vec<(&'static str, String)>, } @@ -163,6 +172,9 @@ mod inner { "step_name" => { self.step_name = Some(value.to_string()); } + "cmd_name" => { + self.cmd_name = Some(value.to_string()); + } name => { self.fields.push((name, value.to_string())); } @@ -187,9 +199,12 @@ mod inner { Enter, } - /// Holds the name of a step, stored in `tracing_subscriber`'s extensions. + /// Holds the name of a step span, stored in `tracing_subscriber`'s extensions. struct StepNameExtension(String); + /// Holds the name of a command span, stored in `tracing_subscriber`'s extensions. + struct CommandNameExtension(String); + #[derive(Default)] struct TracingPrinter { indent: std::sync::atomic::AtomicU32, @@ -264,7 +279,7 @@ mod inner { // We handle steps specially. We instrument them dynamically in `Builder::ensure`, // and we want to have custom name for each step span. But tracing doesn't allow setting // dynamic span names. So we detect step spans here and override their name. - if span.metadata().target() == STEP_NAME_TARGET { + if span.metadata().target() == STEP_SPAN_TARGET { let name = field_values.and_then(|v| v.step_name.as_deref()).unwrap_or(span.name()); write!(writer, "{name}")?; @@ -334,8 +349,14 @@ mod inner { // We need to propagate the actual name of the span to the Chrome layer below, because // it cannot access field values. We do that through extensions. - if let Some(step_name) = field_values.step_name.clone() { + if attrs.metadata().target() == STEP_SPAN_TARGET + && let Some(step_name) = field_values.step_name.clone() + { ctx.span(id).unwrap().extensions_mut().insert(StepNameExtension(step_name)); + } else if attrs.metadata().target() == COMMAND_SPAN_TARGET + && let Some(cmd_name) = field_values.cmd_name.clone() + { + ctx.span(id).unwrap().extensions_mut().insert(CommandNameExtension(cmd_name)); } self.span_values.lock().unwrap().insert(id.clone(), field_values); } From b4a357fbaaac1f79cb6648e8a0a519e96f4cd0fa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 17:33:47 +0200 Subject: [PATCH 12/18] Always profile commands and generate Chrome profile when tracing is enabled --- src/bootstrap/src/bin/main.rs | 22 +++------ src/bootstrap/src/utils/tracing.rs | 71 ++++++++++++++---------------- 2 files changed, 37 insertions(+), 56 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index 0dc3cad0cd8f5..95bd242baf7d8 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -16,19 +16,15 @@ use bootstrap::{ find_recent_config_change_ids, human_readable_changes, symlink_dir, t, }; -fn is_profiling_enabled() -> bool { - env::var("BOOTSTRAP_PROFILE").is_ok_and(|v| v == "1") -} - fn is_tracing_enabled() -> bool { - is_profiling_enabled() || cfg!(feature = "tracing") + cfg!(feature = "tracing") } fn main() { #[cfg(feature = "tracing")] - let guard = bootstrap::setup_tracing(is_profiling_enabled()); + let guard = bootstrap::setup_tracing("BOOTSTRAP_TRACING"); - let start_time = Instant::now(); + let _start_time = Instant::now(); let args = env::args().skip(1).collect::>(); @@ -175,19 +171,11 @@ fn main() { } } - if is_profiling_enabled() { - build.report_summary(&tracing_dir.join("command-stats.txt"), start_time); - } - #[cfg(feature = "tracing")] { + build.report_summary(&tracing_dir.join("command-stats.txt"), _start_time); build.report_step_graph(&tracing_dir); - if let Some(guard) = guard { - guard.copy_to_dir(&tracing_dir); - } - } - - if tracing_enabled { + guard.copy_to_dir(&tracing_dir); eprintln!("Tracing/profiling output has been written to {}", latest_trace_dir.display()); } } diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs index 18d19738de96f..8b9d6ca213c55 100644 --- a/src/bootstrap/src/utils/tracing.rs +++ b/src/bootstrap/src/utils/tracing.rs @@ -92,50 +92,43 @@ mod inner { use crate::STEP_SPAN_TARGET; use crate::utils::tracing::COMMAND_SPAN_TARGET; - pub fn setup_tracing(profiling_enabled: bool) -> Option { - let filter = EnvFilter::from_env("BOOTSTRAP_TRACING"); + pub fn setup_tracing(env_name: &str) -> TracingGuard { + let filter = EnvFilter::from_env(env_name); let registry = tracing_subscriber::registry().with(filter).with(TracingPrinter::default()); - let guard = if profiling_enabled { - // When we're creating this layer, we do not yet know the location of the tracing output - // directory, because it is stored in the output directory determined after Config is parsed, - // but we already want to make tracing calls during (and before) config parsing. - // So we store the output into a temporary file, and then move it to the tracing directory - // before bootstrap ends. - let tempdir = tempfile::TempDir::new().expect("Cannot create temporary directory"); - let chrome_tracing_path = tempdir.path().join("bootstrap-trace.json"); - let file = std::io::BufWriter::new(File::create(&chrome_tracing_path).unwrap()); - - let chrome_layer = tracing_chrome::ChromeLayerBuilder::new() - .writer(file) - .include_args(true) - .name_fn(Box::new(|event_or_span| match event_or_span { - tracing_chrome::EventOrSpan::Event(e) => e.metadata().name().to_string(), - tracing_chrome::EventOrSpan::Span(s) => { - if s.metadata().target() == STEP_SPAN_TARGET - && let Some(extension) = s.extensions().get::() - { - extension.0.clone() - } else if s.metadata().target() == COMMAND_SPAN_TARGET - && let Some(extension) = s.extensions().get::() - { - extension.0.clone() - } else { - s.metadata().name().to_string() - } + // When we're creating this layer, we do not yet know the location of the tracing output + // directory, because it is stored in the output directory determined after Config is parsed, + // but we already want to make tracing calls during (and before) config parsing. + // So we store the output into a temporary file, and then move it to the tracing directory + // before bootstrap ends. + let tempdir = tempfile::TempDir::new().expect("Cannot create temporary directory"); + let chrome_tracing_path = tempdir.path().join("bootstrap-trace.json"); + let file = std::io::BufWriter::new(File::create(&chrome_tracing_path).unwrap()); + + let chrome_layer = tracing_chrome::ChromeLayerBuilder::new() + .writer(file) + .include_args(true) + .name_fn(Box::new(|event_or_span| match event_or_span { + tracing_chrome::EventOrSpan::Event(e) => e.metadata().name().to_string(), + tracing_chrome::EventOrSpan::Span(s) => { + if s.metadata().target() == STEP_SPAN_TARGET + && let Some(extension) = s.extensions().get::() + { + extension.0.clone() + } else if s.metadata().target() == COMMAND_SPAN_TARGET + && let Some(extension) = s.extensions().get::() + { + extension.0.clone() + } else { + s.metadata().name().to_string() } - })); - let (chrome_layer, guard) = chrome_layer.build(); - - tracing::subscriber::set_global_default(registry.with(chrome_layer)).unwrap(); - Some(TracingGuard { guard, _tempdir: tempdir, chrome_tracing_path }) - } else { - tracing::subscriber::set_global_default(registry).unwrap(); - None - }; + } + })); + let (chrome_layer, guard) = chrome_layer.build(); - guard + tracing::subscriber::set_global_default(registry.with(chrome_layer)).unwrap(); + TracingGuard { guard, _tempdir: tempdir, chrome_tracing_path } } pub struct TracingGuard { From f9a458874c3673492ce5382a82de462c844a533e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 17:56:16 +0200 Subject: [PATCH 13/18] Do not create a span for cached commands --- src/bootstrap/src/utils/exec.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/bootstrap/src/utils/exec.rs b/src/bootstrap/src/utils/exec.rs index ac75e27d57c85..9a536f75ab741 100644 --- a/src/bootstrap/src/utils/exec.rs +++ b/src/bootstrap/src/utils/exec.rs @@ -681,9 +681,6 @@ impl ExecutionContext { ) -> DeferredCommand<'a> { let fingerprint = command.fingerprint(); - #[cfg(feature = "tracing")] - let span_guard = crate::utils::tracing::trace_cmd(command); - if let Some(cached_output) = self.command_cache.get(&fingerprint) { command.mark_as_executed(); self.verbose(|| println!("Cache hit: {command:?}")); @@ -691,6 +688,9 @@ impl ExecutionContext { return DeferredCommand { state: CommandState::Cached(cached_output) }; } + #[cfg(feature = "tracing")] + let span_guard = crate::utils::tracing::trace_cmd(command); + let created_at = command.get_created_location(); let executed_at = std::panic::Location::caller(); From 12828f7cb123cd0f66e42da21f314f3ee167363b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 18:20:45 +0200 Subject: [PATCH 14/18] Create tracing directory symlink even during dry run --- src/bootstrap/src/bin/main.rs | 16 ++++++++++++++-- 1 file changed, 14 insertions(+), 2 deletions(-) diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index 95bd242baf7d8..8b2d67266a77b 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -7,13 +7,14 @@ use std::fs::{self, OpenOptions}; use std::io::{self, BufRead, BufReader, IsTerminal, Write}; +use std::path::Path; use std::str::FromStr; use std::time::Instant; use std::{env, process}; use bootstrap::{ Build, CONFIG_CHANGE_HISTORY, ChangeId, Config, Flags, Subcommand, debug, - find_recent_config_change_ids, human_readable_changes, symlink_dir, t, + find_recent_config_change_ids, human_readable_changes, t, }; fn is_tracing_enabled() -> bool { @@ -114,7 +115,18 @@ fn main() { #[cfg(not(windows))] let _ = std::fs::remove_file(&latest_trace_dir); - t!(symlink_dir(&config, &tracing_dir, &latest_trace_dir)); + #[cfg(not(windows))] + fn symlink_dir_inner(original: &Path, link: &Path) -> io::Result<()> { + use std::os::unix::fs; + fs::symlink(original, link) + } + + #[cfg(windows)] + fn symlink_dir_inner(target: &Path, junction: &Path) -> io::Result<()> { + junction::create(target, junction) + } + + t!(symlink_dir_inner(&tracing_dir, &latest_trace_dir)); } debug!("creating new build based on config"); From 3e77562b7d1325ee667a53a7364b463d655ab756 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 18:20:53 +0200 Subject: [PATCH 15/18] Use `pretty_step_name` in `step_graph` --- src/bootstrap/src/core/builder/mod.rs | 6 +++--- src/bootstrap/src/utils/step_graph.rs | 10 ++-------- 2 files changed, 5 insertions(+), 11 deletions(-) diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs index 9dab16f5a42a1..621c1e2c92930 100644 --- a/src/bootstrap/src/core/builder/mod.rs +++ b/src/bootstrap/src/core/builder/mod.rs @@ -1717,7 +1717,7 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s // We cannot use a dynamic name here, so instead we record the actual step name // in the step_name field. "step", - step_name = step_name::(), + step_name = pretty_step_name::(), args = step_debug_args(&step) ); span.entered() @@ -1819,7 +1819,7 @@ You have to build a stage1 compiler for `{}` first, and then use it to build a s } /// Return qualified step name, e.g. `compile::Rustc`. -fn step_name() -> String { +pub fn pretty_step_name() -> String { // Normalize step type path to only keep the module and the type name let path = type_name::().rsplit("::").take(2).collect::>(); path.into_iter().rev().collect::>().join("::") @@ -1834,7 +1834,7 @@ fn step_debug_args(step: &S) -> String { } fn pretty_print_step(step: &S) -> String { - format!("{} {{ {} }}", step_name::(), step_debug_args(step)) + format!("{} {{ {} }}", pretty_step_name::(), step_debug_args(step)) } impl<'a> AsRef for Builder<'a> { diff --git a/src/bootstrap/src/utils/step_graph.rs b/src/bootstrap/src/utils/step_graph.rs index 30a7853b81664..cffe0dbb3e3a5 100644 --- a/src/bootstrap/src/utils/step_graph.rs +++ b/src/bootstrap/src/utils/step_graph.rs @@ -3,7 +3,7 @@ use std::fmt::Debug; use std::io::BufWriter; use std::path::Path; -use crate::core::builder::{AnyDebug, Step}; +use crate::core::builder::{AnyDebug, Step, pretty_step_name}; use crate::t; /// Records the executed steps and their dependencies in a directed graph, @@ -43,13 +43,7 @@ impl StepGraph { metadata.get_target() ) } else { - let type_name = std::any::type_name::(); - type_name - .strip_prefix("bootstrap::core::") - .unwrap_or(type_name) - .strip_prefix("build_steps::") - .unwrap_or(type_name) - .to_string() + pretty_step_name::() }; let node = Node { label, tooltip: node_key.clone() }; From a0306bfa314ba328ddb22123fe021c0ca90a0dec Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 18:10:29 +0200 Subject: [PATCH 16/18] Update debugging/profiling bootstrap page --- .../bootstrapping/debugging-bootstrap.md | 148 ++++++------------ 1 file changed, 49 insertions(+), 99 deletions(-) diff --git a/src/doc/rustc-dev-guide/src/building/bootstrapping/debugging-bootstrap.md b/src/doc/rustc-dev-guide/src/building/bootstrapping/debugging-bootstrap.md index 9c5ebbd36c465..fb90c0fdb4353 100644 --- a/src/doc/rustc-dev-guide/src/building/bootstrapping/debugging-bootstrap.md +++ b/src/doc/rustc-dev-guide/src/building/bootstrapping/debugging-bootstrap.md @@ -1,120 +1,100 @@ # Debugging bootstrap -There are two main ways to debug bootstrap itself. The first is through println logging, and the second is through the `tracing` feature. - -> FIXME: this section should be expanded +There are two main ways of debugging (and profiling bootstrap). The first is through println logging, and the second is through the `tracing` feature. ## `println` logging Bootstrap has extensive unstructured logging. Most of it is gated behind the `--verbose` flag (pass `-vv` for even more detail). -If you want to know which `Step` ran a command, you could invoke bootstrap like so: +If you want to see verbose output of executed Cargo commands and other kinds of detailed logs, pass `-v` or `-vv` when invoking bootstrap. Note that the logs are unstructured and may be overwhelming. ``` $ ./x dist rustc --dry-run -vv learning about cargo running: RUSTC_BOOTSTRAP="1" "/home/jyn/src/rust2/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "metadata" "--format-version" "1" "--no-deps" "--manifest-path" "/home/jyn/src/rust2/Cargo.toml" (failure_mode=Exit) (created at src/bootstrap/src/core/metadata.rs:81:25, executed at src/bootstrap/src/core/metadata.rs:92:50) running: RUSTC_BOOTSTRAP="1" "/home/jyn/src/rust2/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "metadata" "--format-version" "1" "--no-deps" "--manifest-path" "/home/jyn/src/rust2/library/Cargo.toml" (failure_mode=Exit) (created at src/bootstrap/src/core/metadata.rs:81:25, executed at src/bootstrap/src/core/metadata.rs:92:50) -> Assemble { target_compiler: Compiler { stage: 1, host: x86_64-unknown-linux-gnu } } - > Libdir { compiler: Compiler { stage: 1, host: x86_64-unknown-linux-gnu }, target: x86_64-unknown-linux-gnu } - > Sysroot { compiler: Compiler { stage: 1, host: x86_64-unknown-linux-gnu }, force_recompile: false } -Removing sysroot /home/jyn/src/rust2/build/tmp-dry-run/x86_64-unknown-linux-gnu/stage1 to avoid caching bugs - < Sysroot { compiler: Compiler { stage: 1, host: x86_64-unknown-linux-gnu }, force_recompile: false } - < Libdir { compiler: Compiler { stage: 1, host: x86_64-unknown-linux-gnu }, target: x86_64-unknown-linux-gnu } -... -``` - -This will go through all the recursive dependency calculations, where `Step`s internally call `builder.ensure()`, without actually running cargo or the compiler. - -In some cases, even this may not be enough logging (if so, please add more!). In that case, you can omit `--dry-run`, which will show the normal output inline with the debug logging: - -``` - c Sysroot { compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu }, force_recompile: false } -using sysroot /home/jyn/src/rust2/build/x86_64-unknown-linux-gnu/stage0-sysroot -Building stage0 library artifacts (x86_64-unknown-linux-gnu) -running: cd "/home/jyn/src/rust2" && env ... RUSTC_VERBOSE="2" RUSTC_WRAPPER="/home/jyn/src/rust2/build/bootstrap/debug/rustc" "/home/jyn/src/rust2/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "build" "--target" "x86_64-unknown-linux-gnu" "-Zbinary-dep-depinfo" "-Zroot-dir=/home/jyn/src/rust2" "-v" "-v" "--manifest-path" "/home/jyn/src/rust2/library/sysroot/Cargo.toml" "--message-format" "json-render-diagnostics" - 0.293440230s INFO prepare_target{force=false package_id=sysroot v0.0.0 (/home/jyn/src/rust2/library/sysroot) target="sysroot"}: cargo::core::compiler::fingerprint: fingerprint error for sysroot v0.0.0 (/home/jyn/src/rust2/library/sysroot)/Build/TargetInner { name_inferred: true, ..: lib_target("sysroot", ["lib"], "/home/jyn/src/rust2/library/sysroot/src/lib.rs", Edition2021) } ... ``` -In most cases this should not be necessary. +## `tracing` in bootstrap -TODO: we should convert all this to structured logging so it's easier to control precisely. +Bootstrap has a conditional `tracing` feature, which provides the following features: +- It enables structured logging using [`tracing`][tracing] events and spans. +- It generates a [Chrome trace file] that can be used to visualize the hierarchy and durations of executed steps and commands. + - You can open the generated `chrome-trace.json` file using Chrome, on the `chrome://tracing` tab, or e.g. using [Perfetto]. +- It generates [GraphViz] graphs that visualize the dependencies between executed steps. + - You can open the generated `step-graph-*.dot` file using e.g. [xdot] to visualize the step graph, or use e.g. `dot -Tsvg` to convert the GraphViz file to an SVG file. +- It generates a command execution summary, which shows which commands were executed, how many of their executions were cached, and what commands were the slowest to run. + - The generated `command-stats.txt` file is in a simple human-readable format. -## `tracing` in bootstrap +The structured logs will be written to standard error output (`stderr`), while the other outputs will be stored in files in the `/bootstrap-trace/` directory. For convenience, bootstrap will also create a symlink to the latest generated trace output directory at `/bootstrap-trace/latest`. -Bootstrap has conditional [`tracing`][tracing] setup to provide structured logging. +> Note that if you execute bootstrap with `--dry-run`, the tracing output directory might change. Bootstrap will always print a path where the tracing output files were stored at the end of its execution. [tracing]: https://docs.rs/tracing/0.1.41/tracing/index.html +[Chrome trace file]: https://www.chromium.org/developers/how-tos/trace-event-profiling-tool/ +[Perfetto]: https://ui.perfetto.dev/ +[GraphViz]: https://graphviz.org/doc/info/lang.html +[xdot]: https://github.com/jrfonseca/xdot.py ### Enabling `tracing` output -Bootstrap will conditionally build `tracing` support and enable `tracing` output if the `BOOTSTRAP_TRACING` env var is set. - -#### Basic usage - -Example basic usage[^just-trace]: +To enable the conditional `tracing` feature, run bootstrap with the `BOOTSTRAP_TRACING` environment variable. -[^just-trace]: It is not recommended to use *just* `BOOTSTRAP_TRACING=TRACE` because that will dump *everything* at `TRACE` level, including logs intentionally gated behind custom targets as they are too verbose even for `TRACE` level by default. +[tracing_subscriber filter]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html ```bash -$ BOOTSTRAP_TRACING=bootstrap=TRACE ./x build library --stage 1 +$ BOOTSTRAP_TRACING=trace ./x build library --stage 1 ``` Example output[^unstable]: ``` -$ BOOTSTRAP_TRACING=bootstrap=TRACE ./x check src/bootstrap/ +$ BOOTSTRAP_TRACING=trace ./x build library --stage 1 --dry-run Building bootstrap - Compiling bootstrap v0.0.0 (/home/joe/repos/rust/src/bootstrap) - Finished `dev` profile [unoptimized] target(s) in 2.74s - DEBUG bootstrap parsing flags - bootstrap::core::config::flags::Flags::parse args=["check", "src/bootstrap/"] - DEBUG bootstrap parsing config based on flags - DEBUG bootstrap creating new build based on config - bootstrap::Build::build - TRACE bootstrap setting up job management - TRACE bootstrap downloading rustfmt early - bootstrap::handling hardcoded subcommands (Format, Suggest, Perf) - DEBUG bootstrap not a hardcoded subcommand; returning to normal handling, cmd=Check { all_targets: false } - DEBUG bootstrap handling subcommand normally - bootstrap::executing real run - bootstrap::(1) executing dry-run sanity-check - bootstrap::(2) executing actual run -Checking stage0 library artifacts (x86_64-unknown-linux-gnu) - Finished `release` profile [optimized + debuginfo] target(s) in 0.04s -Checking stage0 compiler artifacts {rustc-main, rustc_abi, rustc_arena, rustc_ast, rustc_ast_ir, rustc_ast_lowering, rustc_ast_passes, rustc_ast_pretty, rustc_attr_data_structures, rustc_attr_parsing, rustc_baked_icu_data, rustc_borrowck, rustc_builtin_macros, rustc_codegen_llvm, rustc_codegen_ssa, rustc_const_eval, rustc_data_structures, rustc_driver, rustc_driver_impl, rustc_error_codes, rustc_error_messages, rustc_errors, rustc_expand, rustc_feature, rustc_fluent_macro, rustc_fs_util, rustc_graphviz, rustc_hir, rustc_hir_analysis, rustc_hir_pretty, rustc_hir_typeck, rustc_incremental, rustc_index, rustc_index_macros, rustc_infer, rustc_interface, rustc_lexer, rustc_lint, rustc_lint_defs, rustc_llvm, rustc_log, rustc_macros, rustc_metadata, rustc_middle, rustc_mir_build, rustc_mir_dataflow, rustc_mir_transform, rustc_monomorphize, rustc_next_trait_solver, rustc_parse, rustc_parse_format, rustc_passes, rustc_pattern_analysis, rustc_privacy, rustc_query_impl, rustc_query_system, rustc_resolve, rustc_sanitizers, rustc_serialize, rustc_session, rustc_smir, rustc_span, rustc_symbol_mangling, rustc_target, rustc_trait_selection, rustc_traits, rustc_transmute, rustc_ty_utils, rustc_type_ir, rustc_type_ir_macros, stable_mir} (x86_64-unknown-linux-gnu) - Finished `release` profile [optimized + debuginfo] target(s) in 0.23s -Checking stage0 bootstrap artifacts (x86_64-unknown-linux-gnu) - Checking bootstrap v0.0.0 (/home/joe/repos/rust/src/bootstrap) - Finished `release` profile [optimized + debuginfo] target(s) in 0.64s - DEBUG bootstrap checking for postponed test failures from `test --no-fail-fast` -Build completed successfully in 0:00:08 + Finished `dev` profile [unoptimized] target(s) in 0.05s +15:56:52.477 INFO > tool::LibcxxVersionTool {target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715) +15:56:52.575 INFO > compile::Assemble {target_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }} (builder/mod.rs:1715) +15:56:52.575 INFO > tool::Compiletest {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715) +15:56:52.576 INFO > tool::ToolBuild {build_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu, tool: "compiletest", path: "src/tools/compiletest", mode: ToolBootstrap, source_type: InTree, extra_features: [], allow_features: "internal_output_capture", cargo_args: [], artifact_kind: Binary} (builder/mod.rs:1715) +15:56:52.576 INFO > builder::Libdir {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715) +15:56:52.576 INFO > compile::Sysroot {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, force_recompile: false} (builder/mod.rs:1715) +15:56:52.578 INFO > compile::Assemble {target_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }} (builder/mod.rs:1715) +15:56:52.578 INFO > tool::Compiletest {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715) +15:56:52.578 INFO > tool::ToolBuild {build_compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu, tool: "compiletest", path: "src/tools/compiletest", mode: ToolBootstrap, source_type: InTree, extra_features: [], allow_features: "internal_output_capture", cargo_args: [], artifact_kind: Binary} (builder/mod.rs:1715) +15:56:52.578 INFO > builder::Libdir {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, target: x86_64-unknown-linux-gnu} (builder/mod.rs:1715) +15:56:52.578 INFO > compile::Sysroot {compiler: Compiler { stage: 0, host: x86_64-unknown-linux-gnu, forced_compiler: false }, force_recompile: false} (builder/mod.rs:1715) + Finished `release` profile [optimized] target(s) in 0.11s +Tracing/profiling output has been written to /build/bootstrap-trace/latest +Build completed successfully in 0:00:00 ``` +[^unstable]: This output is always subject to further changes. + #### Controlling tracing output -The env var `BOOTSTRAP_TRACING` accepts a [`tracing` env-filter][tracing-env-filter]. +The environment variable `BOOTSTRAP_TRACING` accepts a [`tracing_subscriber` filter][tracing-env-filter]. If you set `BOOTSTRAP_TRACING=trace`, you will enable all logs, but that can be overwhelming. You can thus use the filter to reduce the amount of data logged. There are two orthogonal ways to control which kind of tracing logs you want: -1. You can specify the log **level**, e.g. `DEBUG` or `TRACE`. -2. You can also control the log **target**, e.g. `bootstrap` or `bootstrap::core::config` vs custom targets like `CONFIG_HANDLING`. - - Custom targets are used to limit what is output when `BOOTSTRAP_TRACING=bootstrap=TRACE` is used, as they can be too verbose even for `TRACE` level by default. Currently used custom targets: - - `CONFIG_HANDLING` - -The `TRACE` filter will enable *all* `trace` level or less verbose level tracing output. +1. You can specify the log **level**, e.g. `debug` or `trace`. + - If you select a level, all events/spans with an equal or higher priority level will be shown. +2. You can also control the log **target**, e.g. `bootstrap` or `bootstrap::core::config` or a custom target like `CONFIG_HANDLING` or `STEP`. + - Custom targets are used to limit what kinds of spans you are interested in, as the `BOOTSTRAP_TRACING=trace` output can be quite verbose. Currently, you can use the following custom targets: + - `CONFIG_HANDLING`: show spans related to config handling + - `STEP`: show all executed steps. Note that executed commands have `info` event level. + - `COMMAND`: show all executed commands. Note that executed commands have `trace` event level. You can of course combine them (custom target logs are typically gated behind `TRACE` log level additionally): ```bash -$ BOOTSTRAP_TRACING=CONFIG_HANDLING=TRACE ./x build library --stage 1 +$ BOOTSTRAP_TRACING=CONFIG_HANDLING=trace,STEP=info,COMMAND=trace ./x build library --stage 1 ``` -[^unstable]: This output is always subject to further changes. - [tracing-env-filter]: https://docs.rs/tracing-subscriber/0.3.19/tracing_subscriber/filter/struct.EnvFilter.html +Note that the level that you specify using `BOOTSTRAP_TRACING` also has an effect on the spans that will be recorded in the Chrome trace file. + ##### FIXME(#96176): specific tracing for `compiler()` vs `compiler_for()` The additional targets `COMPILER` and `COMPILER_FOR` are used to help trace what @@ -123,12 +103,6 @@ if [#96176][cleanup-compiler-for] is resolved. [cleanup-compiler-for]: https://github.com/rust-lang/rust/issues/96176 -### Rendering step graph - -When you run bootstrap with the `BOOTSTRAP_TRACING` environment variable configured, bootstrap will automatically output a DOT file that shows all executed steps and their dependencies. The files will have a prefix `bootstrap-steps`. You can use e.g. `xdot` to visualize the file or e.g. `dot -Tsvg` to convert the DOT file to a SVG file. - -A separate DOT file will be outputted for dry-run and non-dry-run execution. - ### Using `tracing` in bootstrap Both `tracing::*` macros and the `tracing::instrument` proc-macro attribute need to be gated behind `tracing` feature. Examples: @@ -149,15 +123,6 @@ impl Step for Foo { todo!() } - #[cfg_attr( - feature = "tracing", - instrument( - level = "trace", - name = "Foo::run", - skip_all, - fields(compiler = ?builder.compiler), - ), - )] fn run(self, builder: &Builder<'_>) -> Self::Output { trace!(?run, "entered Foo::run"); @@ -172,21 +137,6 @@ For `#[instrument]`, it's recommended to: - Explicitly pick an instrumentation name via `name = ".."` to distinguish between e.g. `run` of different steps. - Take care to not cause diverging behavior via tracing, e.g. building extra things only when tracing infra is enabled. -### Profiling bootstrap - -You can set the `BOOTSTRAP_PROFILE=1` environment variable to enable command execution profiling during bootstrap. This generates: - -* A Chrome trace file (for visualization in `chrome://tracing` or [Perfetto](https://ui.perfetto.dev)) if tracing is enabled via `BOOTSTRAP_TRACING=COMMAND=trace` -* A plain-text summary file, `bootstrap-profile-{pid}.txt`, listing all commands sorted by execution time (slowest first), along with cache hits and working directories - -Note: the `.txt` report is always generated when `BOOTSTRAP_PROFILE=1` is set — tracing is not required. - -Example usage: - -```bash -$ BOOTSTRAP_PROFILE=1 BOOTSTRAP_TRACING=COMMAND=trace ./x build library -``` - ### rust-analyzer integration? Unfortunately, because bootstrap is a `rust-analyzer.linkedProjects`, you can't ask r-a to check/build bootstrap itself with `tracing` feature enabled to get relevant completions, due to lack of support as described in . From 6f584bc21e9446faa982864b3eeb5e6b6dadccf7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Mon, 11 Aug 2025 18:32:05 +0200 Subject: [PATCH 17/18] Print created location of executed commands --- src/bootstrap/src/utils/tracing.rs | 77 ++++++++++++++++++++++-------- 1 file changed, 57 insertions(+), 20 deletions(-) diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs index 8b9d6ca213c55..428ba013c985f 100644 --- a/src/bootstrap/src/utils/tracing.rs +++ b/src/bootstrap/src/utils/tracing.rs @@ -54,13 +54,17 @@ const COMMAND_SPAN_TARGET: &str = "COMMAND"; #[cfg(feature = "tracing")] pub fn trace_cmd(command: &crate::BootstrapCommand) -> tracing::span::EnteredSpan { let fingerprint = command.fingerprint(); + let location = command.get_created_location(); + let location = format!("{}:{}", location.file(), location.line()); + tracing::span!( target: COMMAND_SPAN_TARGET, tracing::Level::TRACE, "cmd", cmd_name = fingerprint.program_name().to_string(), cmd = fingerprint.format_short_cmd(), - full_cmd = ?command + full_cmd = ?command, + location ) .entered() } @@ -269,33 +273,66 @@ mod inner { } } - // We handle steps specially. We instrument them dynamically in `Builder::ensure`, - // and we want to have custom name for each step span. But tracing doesn't allow setting - // dynamic span names. So we detect step spans here and override their name. - if span.metadata().target() == STEP_SPAN_TARGET { - let name = field_values.and_then(|v| v.step_name.as_deref()).unwrap_or(span.name()); - write!(writer, "{name}")?; - - // There should be only one more field called `args` - if let Some(values) = field_values { - let field = &values.fields[0]; - write!(writer, " {{{}}}", field.1)?; - } - } else { - write!(writer, "{}", span.name())?; - if let Some(values) = field_values.filter(|v| !v.fields.is_empty()) { + fn write_fields<'a, I: IntoIterator, W: Write>( + writer: &mut W, + iter: I, + ) -> std::io::Result<()> { + let items = iter.into_iter().collect::>(); + if !items.is_empty() { write!(writer, " [")?; - for (index, (name, value)) in values.fields.iter().enumerate() { + for (index, (name, value)) in items.iter().enumerate() { write!(writer, "{name} = {value}")?; - if index < values.fields.len() - 1 { + if index < items.len() - 1 { write!(writer, ", ")?; } } write!(writer, "]")?; } - }; + Ok(()) + } + + // We handle steps specially. We instrument them dynamically in `Builder::ensure`, + // and we want to have custom name for each step span. But tracing doesn't allow setting + // dynamic span names. So we detect step spans here and override their name. + match span.metadata().target() { + // Executed step + STEP_SPAN_TARGET => { + let name = + field_values.and_then(|v| v.step_name.as_deref()).unwrap_or(span.name()); + write!(writer, "{name}")?; + + // There should be only one more field called `args` + if let Some(values) = field_values { + let field = &values.fields[0]; + write!(writer, " {{{}}}", field.1)?; + } + write_location(writer, span.metadata())?; + } + // Executed command + COMMAND_SPAN_TARGET => { + write!(writer, "{}", span.name())?; + if let Some(values) = field_values { + write_fields( + writer, + values.fields.iter().filter(|(name, _)| *name != "location"), + )?; + write!( + writer, + " ({})", + values.fields.iter().find(|(name, _)| *name == "location").unwrap().1 + )?; + } + } + // Other span + _ => { + write!(writer, "{}", span.name())?; + if let Some(values) = field_values { + write_fields(writer, values.fields.iter())?; + } + write_location(writer, span.metadata())?; + } + } - write_location(writer, span.metadata())?; writeln!(writer)?; Ok(()) } From 0b8c6ad2b7863d34bfe5a55714039d2039a0ede5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jakub=20Ber=C3=A1nek?= Date: Tue, 12 Aug 2025 17:39:07 +0200 Subject: [PATCH 18/18] Remove one dependency from tracing bootstrap build --- src/bootstrap/Cargo.lock | 130 --------------------------------------- src/bootstrap/Cargo.toml | 2 +- 2 files changed, 1 insertion(+), 131 deletions(-) diff --git a/src/bootstrap/Cargo.lock b/src/bootstrap/Cargo.lock index f5d04c39d3f33..605ac687ab814 100644 --- a/src/bootstrap/Cargo.lock +++ b/src/bootstrap/Cargo.lock @@ -11,21 +11,6 @@ dependencies = [ "memchr", ] -[[package]] -name = "android-tzdata" -version = "0.1.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e999941b234f3131b00bc13c22d06e8c5ff726d1b6318ac7eb276997bbb4fef0" - -[[package]] -name = "android_system_properties" -version = "0.1.5" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "819e7219dbd41043ac279b19830f2efc897156490d7fd6ea916720117ee66311" -dependencies = [ - "libc", -] - [[package]] name = "anstyle" version = "1.0.10" @@ -109,12 +94,6 @@ dependencies = [ "serde_derive", ] -[[package]] -name = "bumpalo" -version = "3.19.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "46c5e41b57b8bba42a04676d81cb89e9ee8e859a1a66f80a5a72e1cb76b34d43" - [[package]] name = "cc" version = "1.2.23" @@ -136,12 +115,7 @@ version = "0.4.41" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c469d952047f47f91b68d1cba3f10d63c11d73e4636f24f08daf0278abf01c4d" dependencies = [ - "android-tzdata", - "iana-time-zone", - "js-sys", "num-traits", - "wasm-bindgen", - "windows-link", ] [[package]] @@ -212,12 +186,6 @@ dependencies = [ "windows-sys 0.59.0", ] -[[package]] -name = "core-foundation-sys" -version = "0.8.7" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "773648b94d0e5d620f64f280777445740e61fe701025087ec8b57f45c791888b" - [[package]] name = "cpufeatures" version = "0.2.15" @@ -373,30 +341,6 @@ dependencies = [ "windows-sys 0.52.0", ] -[[package]] -name = "iana-time-zone" -version = "0.1.63" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b0c919e5debc312ad217002b8048a17b7d83f80703865bbfcfebb0458b0b27d8" -dependencies = [ - "android_system_properties", - "core-foundation-sys", - "iana-time-zone-haiku", - "js-sys", - "log", - "wasm-bindgen", - "windows-core", -] - -[[package]] -name = "iana-time-zone-haiku" -version = "0.1.2" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f31827a206f56af32e590ba56d5d2d085f558508192593743f16b2306495269f" -dependencies = [ - "cc", -] - [[package]] name = "ignore" version = "0.4.23" @@ -430,16 +374,6 @@ version = "1.0.11" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49f1f14873335454500d59611f1cf4a4b0f786f9ac11f4312a78e4cf2566695b" -[[package]] -name = "js-sys" -version = "0.3.77" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1cfaf33c695fc6e08064efbc1f72ec937429614f25eef83af942d0e227c3a28f" -dependencies = [ - "once_cell", - "wasm-bindgen", -] - [[package]] name = "junction" version = "1.2.0" @@ -701,12 +635,6 @@ dependencies = [ "windows-sys 0.59.0", ] -[[package]] -name = "rustversion" -version = "1.0.22" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b39cdef0fa800fc44525c84ccb54a029961a8215f9619753635a9c0d2538d46d" - [[package]] name = "ryu" version = "1.0.18" @@ -996,64 +924,6 @@ dependencies = [ "wit-bindgen-rt", ] -[[package]] -name = "wasm-bindgen" -version = "0.2.100" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1edc8929d7499fc4e8f0be2262a241556cfc54a0bea223790e71446f2aab1ef5" -dependencies = [ - "cfg-if", - "once_cell", - "rustversion", - "wasm-bindgen-macro", -] - -[[package]] -name = "wasm-bindgen-backend" -version = "0.2.100" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2f0a0651a5c2bc21487bde11ee802ccaf4c51935d0d3d42a6101f98161700bc6" -dependencies = [ - "bumpalo", - "log", - "proc-macro2", - "quote", - "syn", - "wasm-bindgen-shared", -] - -[[package]] -name = "wasm-bindgen-macro" -version = "0.2.100" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "7fe63fc6d09ed3792bd0897b314f53de8e16568c2b3f7982f468c0bf9bd0b407" -dependencies = [ - "quote", - "wasm-bindgen-macro-support", -] - -[[package]] -name = "wasm-bindgen-macro-support" -version = "0.2.100" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8ae87ea40c9f689fc23f209965b6fb8a99ad69aeeb0231408be24920604395de" -dependencies = [ - "proc-macro2", - "quote", - "syn", - "wasm-bindgen-backend", - "wasm-bindgen-shared", -] - -[[package]] -name = "wasm-bindgen-shared" -version = "0.2.100" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1a05d73b933a847d6cccdda8f838a22ff101ad9bf93e33684f39c1f5f0eece3d" -dependencies = [ - "unicode-ident", -] - [[package]] name = "winapi" version = "0.3.9" diff --git a/src/bootstrap/Cargo.toml b/src/bootstrap/Cargo.toml index ae5a5d798e57c..eb9cfaff31b38 100644 --- a/src/bootstrap/Cargo.toml +++ b/src/bootstrap/Cargo.toml @@ -61,7 +61,7 @@ xz2 = "0.1" sysinfo = { version = "0.36.0", default-features = false, optional = true, features = ["system"] } # Dependencies needed by the `tracing` feature -chrono = { version = "0.4", optional = true } +chrono = { version = "0.4", default-features = false, optional = true, features = ["now", "std"] } tracing = { version = "0.1", optional = true, features = ["attributes"] } tracing-chrome = { version = "0.7", optional = true } tracing-subscriber = { version = "0.3", optional = true, features = ["env-filter", "fmt", "registry", "std"] }