diff --git a/src/bootstrap/Cargo.lock b/src/bootstrap/Cargo.lock index d2f3c7f36ca86..a47f3af60cbd5 100644 --- a/src/bootstrap/Cargo.lock +++ b/src/bootstrap/Cargo.lock @@ -59,6 +59,7 @@ dependencies = [ "termcolor", "toml", "tracing", + "tracing-chrome", "tracing-subscriber", "tracing-tree", "walkdir", @@ -727,6 +728,17 @@ dependencies = [ "syn", ] +[[package]] +name = "tracing-chrome" +version = "0.7.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bf0a738ed5d6450a9fb96e86a23ad808de2b727fd1394585da5cdd6788ffe724" +dependencies = [ + "serde_json", + "tracing-core", + "tracing-subscriber", +] + [[package]] name = "tracing-core" version = "0.1.33" diff --git a/src/bootstrap/Cargo.toml b/src/bootstrap/Cargo.toml index d7afcc7f27d2e..ed51862390d40 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-subscriber", "dep:tracing-tree"] +tracing = ["dep:tracing", "dep:tracing-chrome", "dep:tracing-subscriber", "dep:tracing-tree"] [lib] path = "src/lib.rs" @@ -67,6 +67,7 @@ sysinfo = { version = "0.33.0", default-features = false, optional = true, featu # Dependencies needed by the `tracing` feature 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-tree = { version = "0.4.0", optional = true } diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index 441674936c666..38b380e3db824 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -21,7 +21,7 @@ use tracing::instrument; #[cfg_attr(feature = "tracing", instrument(level = "trace", name = "main"))] fn main() { #[cfg(feature = "tracing")] - setup_tracing(); + let _guard = setup_tracing(); let args = env::args().skip(1).collect::>(); @@ -210,7 +210,7 @@ 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() { +fn setup_tracing() -> impl Drop { use tracing_subscriber::EnvFilter; use tracing_subscriber::layer::SubscriberExt; @@ -218,7 +218,17 @@ fn setup_tracing() { // cf. . let layer = tracing_tree::HierarchicalLayer::default().with_targets(true).with_indent_amount(2); - let registry = tracing_subscriber::registry().with(filter).with(layer); + let mut chrome_layer = tracing_chrome::ChromeLayerBuilder::new().include_args(true); + + // Writes the Chrome profile to trace-.json if enabled + if !env::var("BOOTSTRAP_PROFILE").is_ok_and(|v| v == "1") { + chrome_layer = chrome_layer.writer(io::sink()); + } + + let (chrome_layer, _guard) = chrome_layer.build(); + + let registry = tracing_subscriber::registry().with(filter).with(layer).with(chrome_layer); tracing::subscriber::set_global_default(registry).unwrap(); + _guard } diff --git a/src/bootstrap/src/core/build_steps/compile.rs b/src/bootstrap/src/core/build_steps/compile.rs index a2375842bddef..8e5a8b7e2541c 100644 --- a/src/bootstrap/src/core/build_steps/compile.rs +++ b/src/bootstrap/src/core/build_steps/compile.rs @@ -2234,6 +2234,10 @@ pub fn stream_cargo( cb: &mut dyn FnMut(CargoMessage<'_>), ) -> bool { let mut cmd = cargo.into_cmd(); + + #[cfg(feature = "tracing")] + let _run_span = crate::trace_cmd!(cmd); + let cargo = cmd.as_command_mut(); // 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/lib.rs b/src/bootstrap/src/lib.rs index 665ab117002e0..7cd8aacf0d6c8 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -905,6 +905,9 @@ impl Build { return CommandOutput::default(); } + #[cfg(feature = "tracing")] + let _run_span = trace_cmd!(command); + let created_at = command.get_created_location(); let executed_at = std::panic::Location::caller(); diff --git a/src/bootstrap/src/utils/exec.rs b/src/bootstrap/src/utils/exec.rs index 1902dcd396283..7eb9ab96c8a4a 100644 --- a/src/bootstrap/src/utils/exec.rs +++ b/src/bootstrap/src/utils/exec.rs @@ -329,3 +329,25 @@ impl Default for CommandOutput { } } } + +/// Helper trait to format both Command and BootstrapCommand as a short execution line, +/// without all the other details (e.g. environment variables). +#[allow(unused)] +pub trait FormatShortCmd { + fn format_short_cmd(&self) -> String; +} + +impl FormatShortCmd for BootstrapCommand { + fn format_short_cmd(&self) -> String { + self.command.format_short_cmd() + } +} + +impl FormatShortCmd for Command { + fn format_short_cmd(&self) -> String { + let program = Path::new(self.get_program()); + let mut line = vec![program.file_name().unwrap().to_str().unwrap()]; + line.extend(self.get_args().map(|arg| arg.to_str().unwrap())); + line.join(" ") + } +} diff --git a/src/bootstrap/src/utils/helpers.rs b/src/bootstrap/src/utils/helpers.rs index a1b1748c85b53..3fee397da091d 100644 --- a/src/bootstrap/src/utils/helpers.rs +++ b/src/bootstrap/src/utils/helpers.rs @@ -265,6 +265,9 @@ pub fn make(host: &str) -> PathBuf { #[track_caller] pub fn output(cmd: &mut Command) -> String { + #[cfg(feature = "tracing")] + let _run_span = crate::trace_cmd!(cmd); + let output = match cmd.stderr(Stdio::inherit()).output() { Ok(status) => status, Err(e) => fail(&format!("failed to execute command: {cmd:?}\nERROR: {e}")), diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs index e89decf9e5586..99849341dc3b9 100644 --- a/src/bootstrap/src/utils/tracing.rs +++ b/src/bootstrap/src/utils/tracing.rs @@ -47,3 +47,20 @@ macro_rules! error { ::tracing::error!($($tokens)*) } } + +#[macro_export] +macro_rules! trace_cmd { + ($cmd:expr) => { + { + use $crate::utils::exec::FormatShortCmd; + + ::tracing::span!( + target: "COMMAND", + ::tracing::Level::TRACE, + "executing command", + cmd = $cmd.format_short_cmd(), + full_cmd = ?$cmd + ).entered() + } + }; +} 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 3f907e85dd6cc..04fa5b204dd4e 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 @@ -121,6 +121,14 @@ 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 use the `COMMAND` tracing target to trace execution of most commands spawned by bootstrap. If you also use the `BOOTSTRAP_PROFILE=1` environment variable, bootstrap will generate a Chrome JSON trace file, which can be visualized in Chrome's `chrome://tracing` page or on https://ui.perfetto.dev. + +```bash +$ BOOTSTRAP_TRACING=COMMAND=trace BOOTSTRAP_PROFILE=1 ./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 .