From 9ba7037c9435f30e3e5e6f8b3d5ad017a92640fa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E8=AE=B8=E6=9D=B0=E5=8F=8B=20Jieyou=20Xu=20=28Joe=29?= <39484203+jieyouxu@users.noreply.github.com> Date: Fri, 10 Jan 2025 01:33:33 +0800 Subject: [PATCH] [EXPERIMENTAL] bootstrap: add structured tracing to `./x test tests/ui` and `./x build compiler/rustc_codegen_gcc` flows Example usages: ```bash $ BOOTSTRAP_LOG=bootstrap=TRACE,STEPS_TO_RUN=TRACE ./x build ./compiler/rustc_codegen_gcc/ --stage 1 $ BOOTSTRAP_LOG=bootstrap=TRACE ./x build ./compiler/rustc_codegen_gcc/ --stage 1 $ BOOTSTRAP_LOG=bootstrap=TRACE ./x test tests/ui --stage 1 $ BOOTSTRAP_LOG=bootstrap=TRACE ./x test tests/ui src/tools/run-make-support --stage 1 ``` --- src/bootstrap/Cargo.lock | 196 +++++++++++++- src/bootstrap/Cargo.toml | 6 +- src/bootstrap/src/bin/main.rs | 26 +- src/bootstrap/src/core/build_steps/compile.rs | 79 +++++- src/bootstrap/src/core/builder/mod.rs | 241 ++++++++++++++---- src/bootstrap/src/core/config/config.rs | 48 ++-- src/bootstrap/src/core/config/flags.rs | 6 +- src/bootstrap/src/lib.rs | 40 ++- 8 files changed, 545 insertions(+), 97 deletions(-) diff --git a/src/bootstrap/Cargo.lock b/src/bootstrap/Cargo.lock index c9697e670b777..c46aae2ded1ae 100644 --- a/src/bootstrap/Cargo.lock +++ b/src/bootstrap/Cargo.lock @@ -58,6 +58,9 @@ dependencies = [ "tar", "termcolor", "toml", + "tracing", + "tracing-subscriber", + "tracing-tree", "walkdir", "windows 0.52.0", "xz2", @@ -70,7 +73,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "40723b8fb387abc38f4f4a37c09073622e41dd12327033091ef8950659e6dc0c" dependencies = [ "memchr", - "regex-automata", + "regex-automata 0.4.9", "serde", ] @@ -271,8 +274,8 @@ dependencies = [ "aho-corasick", "bstr", "log", - "regex-automata", - "regex-syntax", + "regex-automata 0.4.9", + "regex-syntax 0.8.5", ] [[package]] @@ -300,7 +303,7 @@ dependencies = [ "globset", "log", "memchr", - "regex-automata", + "regex-automata 0.4.9", "same-file", "walkdir", "winapi-util", @@ -322,6 +325,12 @@ dependencies = [ "windows-sys 0.52.0", ] +[[package]] +name = "lazy_static" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" + [[package]] name = "libc" version = "0.2.167" @@ -362,6 +371,15 @@ dependencies = [ "pkg-config", ] +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "memchr" version = "2.7.4" @@ -377,6 +395,25 @@ dependencies = [ "winapi", ] +[[package]] +name = "nu-ansi-term" +version = "0.46.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" +dependencies = [ + "overload", + "winapi", +] + +[[package]] +name = "nu-ansi-term" +version = "0.50.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d4a28e057d01f97e61255210fcff094d74ed0466038633e95017f5beb68e4399" +dependencies = [ + "windows-sys 0.52.0", +] + [[package]] name = "object" version = "0.36.5" @@ -386,6 +423,12 @@ dependencies = [ "memchr", ] +[[package]] +name = "once_cell" +version = "1.20.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1261fe7e33c73b354eab43b1273a57c8f967d0391e80353e51f764ac02cf6775" + [[package]] name = "opener" version = "0.5.2" @@ -396,6 +439,18 @@ dependencies = [ "winapi", ] +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + +[[package]] +name = "pin-project-lite" +version = "0.2.16" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3b3cff922bd51709b605d9ead9aa71031d81447142d828eb4a6eba76fe619f9b" + [[package]] name = "pkg-config" version = "0.3.31" @@ -439,6 +494,27 @@ dependencies = [ "bitflags", ] +[[package]] +name = "regex" +version = "1.11.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b544ef1b4eac5dc2db33ea63606ae9ffcfac26c1416a2806ae0bf5f56b201191" +dependencies = [ + "aho-corasick", + "memchr", + "regex-automata 0.4.9", + "regex-syntax 0.8.5", +] + +[[package]] +name = "regex-automata" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", +] + [[package]] name = "regex-automata" version = "0.4.9" @@ -447,9 +523,15 @@ checksum = "809e8dc61f6de73b46c85f4c96486310fe304c434cfa43669d7b40f711150908" dependencies = [ "aho-corasick", "memchr", - "regex-syntax", + "regex-syntax 0.8.5", ] +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + [[package]] name = "regex-syntax" version = "0.8.5" @@ -539,12 +621,27 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shlex" version = "1.3.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0fda2ff0d084019ba4d7c6f371c95d8fd75ce3524c3cb8fb653a3023f6323e64" +[[package]] +name = "smallvec" +version = "1.13.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3c5e1a9a646d36c3599cd173a41282daf47c44583ad367b8e6837255952e5c67" + [[package]] name = "syn" version = "2.0.87" @@ -589,6 +686,16 @@ dependencies = [ "winapi-util", ] +[[package]] +name = "thread_local" +version = "1.1.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c" +dependencies = [ + "cfg-if", + "once_cell", +] + [[package]] name = "toml" version = "0.5.11" @@ -598,6 +705,79 @@ dependencies = [ "serde", ] +[[package]] +name = "tracing" +version = "0.1.41" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "784e0ac535deb450455cbfa28a6f0df145ea1bb7ae51b821cf5e7927fdcfbdd0" +dependencies = [ + "pin-project-lite", + "tracing-attributes", + "tracing-core", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.28" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "395ae124c09f9e6918a2310af6038fba074bcf474ac352496d5910dd59a2226d" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "tracing-core" +version = "0.1.33" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c" +dependencies = [ + "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008" +dependencies = [ + "matchers", + "nu-ansi-term 0.46.0", + "once_cell", + "regex", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", +] + +[[package]] +name = "tracing-tree" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f459ca79f1b0d5f71c54ddfde6debfc59c8b6eeb46808ae492077f739dc7b49c" +dependencies = [ + "nu-ansi-term 0.50.1", + "tracing-core", + "tracing-log", + "tracing-subscriber", +] + [[package]] name = "typenum" version = "1.17.0" @@ -610,6 +790,12 @@ version = "1.0.13" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e91b56cd4cadaeb79bbf1a5645f6b4f8dc5bde8834ad5894a8db35fda9efa1fe" +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "version_check" version = "0.9.5" diff --git a/src/bootstrap/Cargo.toml b/src/bootstrap/Cargo.toml index d8775a67e1939..9433405526024 100644 --- a/src/bootstrap/Cargo.toml +++ b/src/bootstrap/Cargo.toml @@ -40,7 +40,7 @@ cc = "=1.2.0" cmake = "=0.1.48" build_helper = { path = "../build_helper" } -clap = { version = "4.4", default-features = false, features = ["std", "usage", "help", "derive", "error-context"] } +clap = { version = "4.4", default-features = false, features = ["derive", "error-context", "help", "std", "usage"] } clap_complete = "4.4" fd-lock = "4.0" home = "0.5" @@ -61,6 +61,10 @@ toml = "0.5" walkdir = "2.4" xz2 = "0.1" +tracing = { version = "0.1.41", features = ["attributes"] } +tracing-subscriber = { version = "0.3.19", features = ["env-filter", "fmt", "registry", "std"] } +tracing-tree = "0.4.0" + # Dependencies needed by the build-metrics feature sysinfo = { version = "0.33.0", default-features = false, optional = true, features = ["system"] } diff --git a/src/bootstrap/src/bin/main.rs b/src/bootstrap/src/bin/main.rs index ee813de1c9e26..566debb409de1 100644 --- a/src/bootstrap/src/bin/main.rs +++ b/src/bootstrap/src/bin/main.rs @@ -15,24 +15,46 @@ use bootstrap::{ human_readable_changes, t, }; use build_helper::ci::CiEnv; +use tracing::*; +use tracing_subscriber::EnvFilter; +use tracing_subscriber::prelude::*; + +fn setup_logging() { + let filter = EnvFilter::from_env("BOOTSTRAP_LOG"); + let layer = tracing_tree::HierarchicalLayer::default() + .with_writer(std::io::stderr) + .with_ansi(true) + .with_targets(true) + .with_bracketed_fields(true) + .with_indent_amount(2) + .with_indent_lines(true); + let subscriber = tracing_subscriber::registry().with(filter).with(layer); + + tracing::subscriber::set_global_default(subscriber).unwrap(); +} +#[instrument(level = "trace", name = "main")] fn main() { + setup_logging(); let args = env::args().skip(1).collect::>(); + trace!(?args, "main binary invoked"); if Flags::try_parse_verbose_help(&args) { return; } let flags = Flags::parse(&args); + trace!("parsed `Flags`"); let config = Config::parse(flags); + trace!("parsed `Config`"); let mut build_lock; let _build_lock_guard; if !config.bypass_bootstrap_lock { - // Display PID of process holding the lock - // PID will be stored in a lock file + // Display PID of process holding the lock. PID will be stored in a lock file. let lock_path = config.out.join("lock"); + trace!(lock_path = ?lock_path.display(), "establishing bootstrap lock"); let pid = fs::read_to_string(&lock_path); build_lock = fd_lock::RwLock::new(t!(fs::OpenOptions::new() diff --git a/src/bootstrap/src/core/build_steps/compile.rs b/src/bootstrap/src/core/build_steps/compile.rs index 4c4df922b3799..f21aeebf01ac4 100644 --- a/src/bootstrap/src/core/build_steps/compile.rs +++ b/src/bootstrap/src/core/build_steps/compile.rs @@ -16,6 +16,7 @@ use std::process::Stdio; use std::{env, fs, str}; use serde_derive::Deserialize; +use tracing::*; use crate::core::build_steps::tool::SourceType; use crate::core::build_steps::{dist, llvm}; @@ -98,13 +99,16 @@ impl Step for Std { run.crate_or_deps("sysroot").path("library").alias("core") } + #[instrument(level = "trace", name = "compile::Std::make_run", skip_all)] fn make_run(run: RunConfig<'_>) { let crates = std_crates_for_run_make(&run); + // NOTE: this is completely unrelated to the `run-make` test suite :3 + trace!(crates_for_run_make = ?crates); let builder = run.builder; - // Force compilation of the standard library from source if the `library` is modified. This allows - // library team to compile the standard library without needing to compile the compiler with - // the `rust.download-rustc=true` option. + // Force compilation of the standard library from source if the `library` is modified. This + // allows library team to compile the standard library without needing to compile the + // compiler with the `rust.download-rustc=true` option. let force_recompile = builder.rust_info().is_managed_git_subrepository() && builder.download_rustc() && builder.config.last_modified_commit(&["library"], "download-rustc", true).is_none(); @@ -124,6 +128,17 @@ 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. + #[instrument( + level = "trace", + name = "compile::Std::run", + skip_all, + fields( + target = ?self.target, + compiler = ?self.compiler, + subset_crates = ?self.crates, + is_for_mir_opt_tests, + ), + )] fn run(self, builder: &Builder<'_>) { let target = self.target; let compiler = self.compiler; @@ -868,6 +883,7 @@ impl Step for Rustc { const ONLY_HOSTS: bool = true; const DEFAULT: bool = false; + #[instrument(level = "trace", name = "compile::Rustc::should_run", skip_all)] fn should_run(run: ShouldRun<'_>) -> ShouldRun<'_> { let mut crates = run.builder.in_tree_crates("rustc-main", None); for (i, krate) in crates.iter().enumerate() { @@ -881,8 +897,10 @@ impl Step for Rustc { run.crates(crates) } + #[instrument(level = "trace", name = "compile::Rustc::make_run", skip_all)] fn make_run(run: RunConfig<'_>) { let crates = run.cargo_crates_in_set(); + trace!(?crates); run.builder.ensure(Rustc { compiler: run.builder.compiler(run.builder.top_stage, run.build_triple()), target: run.target, @@ -895,6 +913,12 @@ impl Step for Rustc { /// This will build the compiler 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. + #[instrument( + level = "trace", + name = "compile::Rustc::run", + skip_all, + fields(target = ?self.target, previous_compiler = ?self.compiler, subset_crates = ?self.crates) + )] fn run(self, builder: &Builder<'_>) -> u32 { let compiler = self.compiler; let target = self.target; @@ -1398,29 +1422,47 @@ impl Step for CodegenBackend { run.paths(&["compiler/rustc_codegen_cranelift", "compiler/rustc_codegen_gcc"]) } + #[instrument(level = "trace", name = "compile::CodegenBackend::make_run", skip_all)] fn make_run(run: RunConfig<'_>) { + trace!("checking if `codegen-backend` config is needed"); if needs_codegen_config(&run) { return; } - for backend in run.builder.config.codegen_backends(run.target) { - if backend == "llvm" { - continue; // Already built as part of rustc - } + let backends = run.builder.config.codegen_backends(run.target); + let codegen_backends_span = + trace_span!("building each requested codegen backend", ?backends); + codegen_backends_span.in_scope(|| { + for backend in backends { + if backend == "llvm" { + trace!("skipping `llvm` because it's already built as part of rustc"); + continue; + } - run.builder.ensure(CodegenBackend { - target: run.target, - compiler: run.builder.compiler(run.builder.top_stage, run.build_triple()), - backend: backend.clone(), - }); - } + let codegen_backend_span = trace_span!("building codegen backend", ?backend); + codegen_backend_span.in_scope(|| { + run.builder.ensure(CodegenBackend { + target: run.target, + compiler: run.builder.compiler(run.builder.top_stage, run.build_triple()), + backend: backend.clone(), + }); + }); + } + }); } + #[instrument( + level = "trace", + name = "compile::CodegenBackend::run", + skip_all, + fields(backend = self.backend) + )] fn run(self, builder: &Builder<'_>) { let compiler = self.compiler; let target = self.target; let backend = self.backend; + trace!(?compiler, ?target, "building a compiler"); builder.ensure(Rustc::new(compiler, target)); if builder.config.keep_stage.contains(&compiler.stage) { @@ -1435,11 +1477,17 @@ impl Step for CodegenBackend { let compiler_to_use = builder.compiler_for(compiler.stage, compiler.host, target); if compiler_to_use != compiler { + trace!( + ?compiler_to_use, + ?compiler, + "`compiler_to_use` diverges from available compiler, building codegen backend with `compiler_to_use`" + ); builder.ensure(CodegenBackend { compiler: compiler_to_use, target, backend }); return; } let out_dir = builder.cargo_out(compiler, Mode::Codegen, target); + trace!(?out_dir); let mut cargo = builder::Cargo::new( builder, @@ -1457,7 +1505,11 @@ impl Step for CodegenBackend { let tmp_stamp = BuildStamp::new(&out_dir).with_prefix("tmp"); let _guard = builder.msg_build(compiler, format_args!("codegen backend {backend}"), target); + + trace!("running cargo to build codegen backend"); let files = run_cargo(builder, cargo, vec![], &tmp_stamp, vec![], false, false); + trace!(built_artifacts = ?files, "built codegen backend artifacts"); + if builder.config.dry_run() { return; } @@ -1478,6 +1530,7 @@ impl Step for CodegenBackend { } let stamp = build_stamp::codegen_backend_stamp(builder, compiler, target, &backend); let codegen_backend = codegen_backend.to_str().unwrap(); + trace!(stamp_path = ?stamp.path(), ?codegen_backend); t!(stamp.add_stamp(codegen_backend).write()); } } diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs index 17de176242732..506909c37b353 100644 --- a/src/bootstrap/src/core/builder/mod.rs +++ b/src/bootstrap/src/core/builder/mod.rs @@ -10,6 +10,7 @@ use std::time::{Duration, Instant}; use std::{env, fs}; use clap::ValueEnum; +use tracing::*; pub use self::cargo::Cargo; pub use crate::Compiler; @@ -191,6 +192,7 @@ pub fn crate_description(crates: &[impl AsRef]) -> String { descr } +#[derive(Debug)] struct StepDescription { default: bool, only_hosts: bool, @@ -340,7 +342,26 @@ const PATH_REMAP: &[(&str, &[&str])] = &[ ]), ]; +#[instrument(level = "trace", name = "remap_paths", skip_all)] fn remap_paths(paths: &mut Vec) { + // NOTE: there are three key points here: + // + // 1. Path remapping here can map a single input path to multiple paths! + // 2. `rust-analyzer-proc-macro-srv` -> `src/tools/rust-analyzer/crates/proc-macro-srv-cli` + // seems to be for `config.toml`. + // 3. (Important!) apparently, `./x test tests` actually fans out right here to become + // effectively `./x test tests/assembly ... tests/ui-fulldeps` (illustrative description). + // + // QUESTION: now that the `PathSet` matching is match-all and not first-consume, if the + // individual test suite steps each matched on a path prefix (`tests/run-make` would + // prefix-match `tests`), is this remapping actually necessary? + // + // Important context: + // - https://github.com/rust-lang/rust/commit/0da0a2196d2d7b37bd5e07ce18b03568e2711f39 + // - https://github.com/rust-lang/rust/pull/96501 + // - https://github.com/rust-lang/rust/pull/96501#discussion_r873076120 + trace!(input_paths = ?paths, "remapping paths"); + let mut remove = vec![]; let mut add = vec![]; for (i, path) in paths.iter().enumerate().filter_map(|(i, path)| path.to_str().map(|s| (i, s))) @@ -400,8 +421,16 @@ impl StepDescription { } } + #[instrument( + level = "trace", + name = "StepDescription::maybe_run", + skip_all, + fields(name = self.name, pathsets = ?pathsets) + )] fn maybe_run(&self, builder: &Builder<'_>, mut pathsets: Vec) { + trace!(initial_pathsets = ?pathsets, "filtering out excluded `PathSet`s"); pathsets.retain(|set| !self.is_excluded(builder, set)); + trace!(filtered_pathsets = ?pathsets); if pathsets.is_empty() { return; @@ -410,10 +439,13 @@ impl StepDescription { // Determine the targets participating in this rule. let targets = if self.only_hosts { &builder.hosts } else { &builder.targets }; - for target in targets { - let run = RunConfig { builder, paths: pathsets.clone(), target: *target }; - (self.make_run)(run); - } + let all_targets_span = trace_span!("invoking `Step::make_run` for each target", ?targets); + all_targets_span.in_scope(|| { + for target in targets { + let run = RunConfig { builder, paths: pathsets.clone(), target: *target }; + (self.make_run)(run); + } + }); } fn is_excluded(&self, builder: &Builder<'_>, pathset: &PathSet) -> bool { @@ -435,7 +467,11 @@ impl StepDescription { false } + #[instrument(level = "trace", name = "StepDescription::run", skip_all)] fn run(v: &[StepDescription], builder: &Builder<'_>, paths: &[PathBuf]) { + trace!("running step descriptions"); + + trace!("collecting `should_run`s"); let should_runs = v .iter() .map(|desc| (desc.should_run)(ShouldRun::new(builder, desc.kind))) @@ -450,6 +486,9 @@ impl StepDescription { crate::exit!(1); } + trace!( + "performing sanity check on rules to make sure each `Step::should_run` has at least one `PathSet`" + ); // sanity checks on rules for (desc, should_run) in v.iter().zip(&should_runs) { assert!( @@ -459,6 +498,10 @@ impl StepDescription { ); } + // NOTE: `--include-default-paths` was added in https://github.com/rust-lang/rust/pull/77762 + // to help with release process (related to `build-manifest`) it seems. For normal + // contributor workflow purposes this can probably be ignored. + trace!("handling empty paths `Step::default`s"); if paths.is_empty() || builder.config.include_default_paths { for (desc, should_run) in v.iter().zip(&should_runs) { if desc.default && should_run.is_really_default() { @@ -467,11 +510,16 @@ impl StepDescription { } } + // NOTE: there is a mix of on-disk paths vs step names (or aliases) here. + trace!( + "resolving on-disk paths relative to build source directory (make absolute -> strip prefix)" + ); // Attempt to resolve paths to be relative to the builder source directory. let mut paths: Vec = paths .iter() .map(|p| { - // If the path does not exist, it may represent the name of a Step, such as `tidy` in `x test tidy` + // If the path does not exist, it may represent the name of a Step, such as `tidy` + // in `x test tidy`. if !p.exists() { return p.clone(); } @@ -486,66 +534,147 @@ impl StepDescription { } }) .collect(); + trace!(?paths, "relativized on-disk paths + step names / aliases"); remap_paths(&mut paths); - - // Handle all test suite paths. - // (This is separate from the loop below to avoid having to handle multiple paths in `is_suite_path` somehow.) - paths.retain(|path| { - for (desc, should_run) in v.iter().zip(&should_runs) { - if let Some(suite) = should_run.is_suite_path(path) { - desc.maybe_run(builder, vec![suite.clone()]); - return false; + trace!(?paths, "remapped paths"); + + // NOTE: this is related to `Step::suite_path`, which means that compiletest test suites + // have **special handling** here compared to crate tests or tool-based tests! + + // Handle all test suite paths. (This is separate from the loop below to avoid having to + // handle multiple paths in `is_suite_path` somehow.) + + let suite_path_handling_span = trace_span!("compiletest suite path handling", ?paths); + suite_path_handling_span.in_scope(|| { + trace!("checking if paths matching compiletest `suite_path`s should be removed"); + paths.retain(|path| { + for (desc, should_run) in v.iter().zip(&should_runs) { + if let Some(suite) = should_run.is_suite_path(path) { + trace!(?path, "removing path because it is a compiletest suite path"); + desc.maybe_run(builder, vec![suite.clone()]); + return false; + } } - } - true + true + }); }); + trace!(?paths, "after removing compiletest suite paths"); + if paths.is_empty() { return; } + // NOTE: so this converts the previous `paths` into a collection of `CLIStepPath`s. let mut paths: Vec = paths.into_iter().map(|p| p.into()).collect(); - let mut path_lookup: Vec<(CLIStepPath, bool)> = - paths.clone().into_iter().map(|p| (p, false)).collect(); - // List of `(usize, &StepDescription, Vec)` where `usize` is the closest index of a path - // compared to the given CLI paths. So we can respect to the CLI order by using this value to sort - // the steps. - let mut steps_to_run = vec![]; + let ordinary_path_handling_span = trace_span!("ordinary path handling", ?paths); + ordinary_path_handling_span.in_scope(|| { + let mut path_lookup: Vec<(CLIStepPath, bool)> = + paths.clone().into_iter().map(|p| (p, false)).collect(); - for (desc, should_run) in v.iter().zip(&should_runs) { - let pathsets = should_run.pathset_for_paths_removing_matches(&mut paths, desc.kind); - - // This value is used for sorting the step execution order. - // By default, `usize::MAX` is used as the index for steps to assign them the lowest priority. - // - // If we resolve the step's path from the given CLI input, this value will be updated with - // the step's actual index. - let mut closest_index = usize::MAX; - - // Find the closest index from the original list of paths given by the CLI input. - for (index, (path, is_used)) in path_lookup.iter_mut().enumerate() { - if !*is_used && !paths.contains(path) { - closest_index = index; - *is_used = true; - break; - } + struct StepToRun<'step> { + closest_index: usize, + step_desc: &'step StepDescription, + pathsets: Vec, } - steps_to_run.push((closest_index, desc, pathsets)); - } + // List of `(usize, &StepDescription, Vec)` where `usize` is the closest index of a + // path compared to the given CLI paths. So we can respect to the CLI order by using this + // value to sort the steps. + let mut steps_to_run: Vec> = vec![]; + + let steps_to_run_building_span = trace_span!("building `steps_to_run`"); + steps_to_run_building_span.in_scope(|| { + // NOTE: previously in + // https://github.com/rust-lang/rust/commit/0da0a2196d2d7b37bd5e07ce18b03568e2711f39, we + // would actually remove paths as they're matched. However, + // https://github.com/rust-lang/rust/pull/133492 changed `PathSet` matching to *also* permit + // prefixes, which broke stuff like `./x check compiler --stage 0` due to dynamic step + // description registration order causing `compiler` path to be consumed by the first + // eligible step. + // + // QUESTION: does the current run-all-match scheme regress + // 0da0a2196d2d7b37bd5e07ce18b03568e2711f39's intention, in particular, + // + // > 5. Remove paths as they're matched + // > + // > This allows checking at the end that no invalid paths are left over. Note that if two + // > steps matched the same path, this will no longer run both; but that's a bug anyway. + for (desc, should_run) in v.iter().zip(&should_runs) { + let _inner_span_guard = + trace_span!(target: "STEPS_TO_RUN", "processing description \"{desc}\"", desc = desc.name) + .entered(); + + // NOTE: reproduced doc comment for `pathset_for_paths_removing_matches` here to inline + // the reasoning. + + // Given a set of requested paths, return the subset which match the Step for this + // `ShouldRun`, removing the matches from `paths`. + // + // NOTE: this returns multiple PathSets to allow for the possibility of multiple units + // of work within the same step. For example, `test::Crate` allows testing multiple + // crates in the same cargo invocation, which are put into separate sets because they + // aren't aliases. + // + // The reason we return PathSet instead of PathBuf is to allow for aliases that mean the + // same thing (for now, just `all_krates` and `paths`, but we may want to add an + // `aliases` function in the future?) + + trace!( + target: "STEPS_TO_RUN", + ?paths, + "desc.kind" = ?desc.kind, + "before `pathset_for_paths_removing_matches`" + ); + let pathsets = + should_run.pathset_for_paths_removing_matches(&mut paths, desc.kind); + trace!( + target: "STEPS_TO_RUN", + ?paths, + "desc.kind" = ?desc.kind, + ?pathsets, + "after `pathset_for_paths_removing_matches`" + ); + + // This value is used for sorting the step execution order. By default, `usize::MAX` is + // used as the index for steps to assign them the lowest priority. + // + // If we resolve the step's path from the given CLI input, this value will be updated + // with the step's actual index. + let mut closest_index = usize::MAX; + + // Find the closest index from the original list of paths given by the CLI input. + for (index, (path, is_used)) in path_lookup.iter_mut().enumerate() { + if !*is_used && !paths.contains(path) { + closest_index = index; + *is_used = true; + break; + } + } - // Sort the steps before running them to respect the CLI order. - steps_to_run.sort_by_key(|(index, _, _)| *index); + steps_to_run.push(StepToRun { closest_index, step_desc: desc, pathsets }); + } + }); - // Handle all PathSets. - for (_index, desc, pathsets) in steps_to_run { - if !pathsets.is_empty() { - desc.maybe_run(builder, pathsets); - } - } + // Sort the steps before running them to respect the CLI order. + steps_to_run.sort_by_key(|s| s.closest_index); + trace!("finalized `steps_to_run`"); + + // Handle all PathSets. + let run_all_span = trace_span!("running all `steps_to_run`"); + run_all_span.in_scope(|| { + for StepToRun { step_desc, pathsets, .. } in steps_to_run { + if !pathsets.is_empty() { + trace!(desc_name = step_desc.name, ?pathsets, "invoking `Step::maybe_run`"); + step_desc.maybe_run(builder, pathsets); + } + } + }); + }); + trace!("performing path handling exhaustiveness check"); paths.retain(|p| !p.will_be_executed); if !paths.is_empty() { @@ -708,8 +837,9 @@ impl<'a> ShouldRun<'a> { /// within the same step. For example, `test::Crate` allows testing multiple crates in the same /// cargo invocation, which are put into separate sets because they aren't aliases. /// - /// The reason we return PathSet instead of PathBuf is to allow for aliases that mean the same thing - /// (for now, just `all_krates` and `paths`, but we may want to add an `aliases` function in the future?) + /// The reason we return PathSet instead of PathBuf is to allow for aliases that mean the same + /// thing (for now, just `all_krates` and `paths`, but we may want to add an `aliases` function + /// in the future?) fn pathset_for_paths_removing_matches( &self, paths: &mut [CLIStepPath], @@ -846,7 +976,10 @@ impl Step for Libdir { } impl<'a> Builder<'a> { + #[instrument(level = "trace", name = "Builder::get_step_descriptions", skip_all)] fn get_step_descriptions(kind: Kind) -> Vec { + trace!("dynamically building step descriptions"); + macro_rules! describe { ($($rule:ty),+ $(,)?) => {{ vec![$(StepDescription::from::<$rule>(kind)),+] @@ -1134,6 +1267,7 @@ impl<'a> Builder<'a> { Some(help) } + #[instrument(level = "trace", name = "Builder::new_internal", skip_all)] fn new_internal(build: &Build, kind: Kind, paths: Vec) -> Builder<'_> { Builder { build, @@ -1146,8 +1280,11 @@ impl<'a> Builder<'a> { } } + #[instrument(level = "trace", name = "Builder::new", skip_all)] pub fn new(build: &Build) -> Builder<'_> { let paths = &build.config.paths; + trace!(?paths, "constructing new `Builder`"); + let (kind, paths) = match build.config.cmd { Subcommand::Build => (Kind::Build, &paths[..]), Subcommand::Check { .. } => (Kind::Check, &paths[..]), @@ -1171,9 +1308,12 @@ impl<'a> Builder<'a> { Subcommand::Perf { .. } => (Kind::Perf, &paths[..]), }; + trace!(?kind, ?paths); + Self::new_internal(build, kind, paths.to_owned()) } + #[instrument(level = "trace", name = "Builder::execute_cli", skip_all)] pub fn execute_cli(&self) { self.run_step_descriptions(&Builder::get_step_descriptions(self.kind), &self.paths); } @@ -1194,6 +1334,7 @@ impl<'a> Builder<'a> { format!("https://doc.rust-lang.org/{channel}") } + #[instrument(level = "trace", name = "Builder::run_step_descriptions", skip_all)] fn run_step_descriptions(&self, v: &[StepDescription], paths: &[PathBuf]) { StepDescription::run(v, self, paths); } diff --git a/src/bootstrap/src/core/config/config.rs b/src/bootstrap/src/core/config/config.rs index 026380a46c685..38c08fe49eb5f 100644 --- a/src/bootstrap/src/core/config/config.rs +++ b/src/bootstrap/src/core/config/config.rs @@ -18,6 +18,7 @@ use build_helper::exit; use build_helper::git::{GitConfig, get_closest_merge_commit, output_result}; use serde::{Deserialize, Deserializer}; use serde_derive::Deserialize; +use tracing::*; use crate::core::build_steps::compile::CODEGEN_BACKEND_PREFIX; use crate::core::build_steps::llvm; @@ -1225,7 +1226,10 @@ define_config! { } impl Config { + #[instrument(level = "trace", skip_all)] pub fn default_opts() -> Config { + trace!("creating `Config` with default opts"); + Config { bypass_bootstrap_lock: false, llvm_optimize: true, @@ -1309,10 +1313,12 @@ impl Config { }) } + #[instrument(level = "trace", name = "Config::parse", skip_all)] pub fn parse(flags: Flags) -> Config { Self::parse_inner(flags, Self::get_toml) } + #[instrument(level = "trace", name = "Config::parse_inner", skip_all)] pub(crate) fn parse_inner( mut flags: Flags, get_toml: impl Fn(&Path) -> Result, @@ -1356,16 +1362,18 @@ impl Config { // Infer the rest of the configuration. - // Infer the source directory. This is non-trivial because we want to support a downloaded bootstrap binary, - // running on a completely different machine from where it was compiled. + // Infer the source directory. This is non-trivial because we want to support a downloaded + // bootstrap binary, running on a completely different machine from where it was compiled. let mut cmd = helpers::git(None); - // NOTE: we cannot support running from outside the repository because the only other path we have available - // is set at compile time, which can be wrong if bootstrap was downloaded rather than compiled locally. - // We still support running outside the repository if we find we aren't in a git directory. - - // NOTE: We get a relative path from git to work around an issue on MSYS/mingw. If we used an absolute path, - // and end up using MSYS's git rather than git-for-windows, we would get a unix-y MSYS path. But as bootstrap - // has already been (kinda-cross-)compiled to Windows land, we require a normal Windows path. + // NOTE: we cannot support running from outside the repository because the only other path + // we have available is set at compile time, which can be wrong if bootstrap was downloaded + // rather than compiled locally. We still support running outside the repository if we find + // we aren't in a git directory. + + // NOTE: We get a relative path from git to work around an issue on MSYS/mingw. If we used + // an absolute path, and end up using MSYS's git rather than git-for-windows, we would get a + // unix-y MSYS path. But as bootstrap has already been (kinda-cross-)compiled to Windows + // land, we require a normal Windows path. cmd.arg("rev-parse").arg("--show-cdup"); // Discard stderr because we expect this to fail when building from a tarball. let output = cmd @@ -1376,8 +1384,8 @@ impl Config { .and_then(|output| if output.status.success() { Some(output) } else { None }); if let Some(output) = output { let git_root_relative = String::from_utf8(output.stdout).unwrap(); - // We need to canonicalize this path to make sure it uses backslashes instead of forward slashes, - // and to resolve any relative components. + // We need to canonicalize this path to make sure it uses backslashes instead of forward + // slashes, and to resolve any relative components. let git_root = env::current_dir() .unwrap() .join(PathBuf::from(git_root_relative.trim())) @@ -1390,12 +1398,13 @@ impl Config { Some(p) => PathBuf::from(p), None => git_root, }; - // If this doesn't have at least `stage0`, we guessed wrong. This can happen when, - // for example, the build directory is inside of another unrelated git directory. - // In that case keep the original `CARGO_MANIFEST_DIR` handling. + // If this doesn't have at least `stage0`, we guessed wrong. This can happen when, for + // example, the build directory is inside of another unrelated git directory. In that + // case keep the original `CARGO_MANIFEST_DIR` handling. // - // NOTE: this implies that downloadable bootstrap isn't supported when the build directory is outside - // the source directory. We could fix that by setting a variable from all three of python, ./x, and x.ps1. + // NOTE: this implies that downloadable bootstrap isn't supported when the build + // directory is outside the source directory. We could fix that by setting a variable + // from all three of python, ./x, and x.ps1. if git_root.join("src").join("stage0").exists() { config.src = git_root; } @@ -1416,7 +1425,8 @@ impl Config { config.stage0_metadata = build_helper::stage0_parser::parse_stage0_file(); - // Read from `--config`, then `RUST_BOOTSTRAP_CONFIG`, then `./config.toml`, then `config.toml` in the root directory. + // Read from `--config`, then `RUST_BOOTSTRAP_CONFIG`, then `./config.toml`, then + // `config.toml` in the root directory. let toml_path = flags .config .clone() @@ -1430,8 +1440,8 @@ impl Config { let file_content = t!(fs::read_to_string(config.src.join("src/ci/channel"))); let ci_channel = file_content.trim_end(); - // Give a hard error if `--config` or `RUST_BOOTSTRAP_CONFIG` are set to a missing path, - // but not if `config.toml` hasn't been created. + // Give a hard error if `--config` or `RUST_BOOTSTRAP_CONFIG` are set to a missing path, but + // not if `config.toml` hasn't been created. let mut toml = if !using_default_path || toml_path.exists() { config.config = Some(if cfg!(not(test)) { toml_path.canonicalize().unwrap() diff --git a/src/bootstrap/src/core/config/flags.rs b/src/bootstrap/src/core/config/flags.rs index f17103f97dc40..c96680f4fa222 100644 --- a/src/bootstrap/src/core/config/flags.rs +++ b/src/bootstrap/src/core/config/flags.rs @@ -6,6 +6,7 @@ use std::path::{Path, PathBuf}; use clap::{CommandFactory, Parser, ValueEnum}; +use tracing::*; use crate::core::build_steps::setup::Profile; use crate::core::builder::{Builder, Kind}; @@ -211,8 +212,11 @@ impl Flags { } } + #[instrument(level = "trace", name = "Flags::parse" skip_all)] pub fn parse(args: &[String]) -> Self { - Flags::parse_from(normalize_args(args)) + let flags = Flags::parse_from(normalize_args(args)); + trace!(?flags, "parsed as `Flags`"); + flags } } diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs index ebe2c332258d7..30dac18fb3373 100644 --- a/src/bootstrap/src/lib.rs +++ b/src/bootstrap/src/lib.rs @@ -28,6 +28,7 @@ use std::{env, fs, io, str}; use build_helper::ci::gha; use build_helper::exit; use termcolor::{ColorChoice, StandardStream, WriteColor}; +use tracing::*; use utils::build_stamp::BuildStamp; use utils::channel::GitInfo; @@ -277,9 +278,11 @@ impl Build { /// line and the filesystem `config`. /// /// By default all build output will be placed in the current directory. + #[instrument(level = "trace", name = "Build::new", skip_all)] pub fn new(mut config: Config) -> Build { let src = config.src.clone(); let out = config.out.clone(); + trace!(?src, ?out); #[cfg(unix)] // keep this consistent with the equivalent check in x.py: @@ -337,7 +340,8 @@ impl Build { bootstrap_out.pop(); } if !bootstrap_out.join(exe("rustc", config.build)).exists() && !cfg!(test) { - // this restriction can be lifted whenever https://github.com/rust-lang/rfcs/pull/3028 is implemented + // This restriction can be lifted whenever https://github.com/rust-lang/rfcs/pull/3028 + // is implemented. panic!( "`rustc` not found in {}, run `cargo build --bins` before `cargo run`", bootstrap_out.display() @@ -391,6 +395,8 @@ impl Build { metrics: crate::utils::metrics::BuildMetrics::init(), }; + trace!("initial `Build` constructed"); + // If local-rust is the same major.minor as the current version, then force a // local-rebuild let local_version_verbose = @@ -464,12 +470,15 @@ impl Build { /// /// The given `err_hint` will be shown to the user if the submodule is not /// checked out and submodule management is disabled. + #[instrument(level = "trace", name = "Build::require_submodule", skip_all, fields(?submodule))] pub fn require_submodule(&self, submodule: &str, err_hint: Option<&str>) { // When testing bootstrap itself, it is much faster to ignore // submodules. Almost all Steps work fine without their submodules. if cfg!(test) && !self.config.submodules() { return; } + + trace!(?submodule, "updating submodule"); self.config.update_submodule(submodule); let absolute_path = self.config.src.join(submodule); if dir_is_empty(&absolute_path) { @@ -537,17 +546,23 @@ impl Build { } /// Executes the entire build, as configured by the flags and configuration. + #[instrument(level = "trace", name = "Build::build", skip_all)] pub fn build(&mut self) { + trace!("executing build"); + unsafe { crate::utils::job::setup(self); } // Download rustfmt early so that it can be used in rust-analyzer configs. + trace!("downloading initial rustfmt early"); let _ = &builder::Builder::new(self).initial_rustfmt(); + trace!(cmd = ?self.config.cmd, "handling hardcoded subcommands (Format, Suggest, Perf)"); // hardcoded subcommands match &self.config.cmd { Subcommand::Format { check, all } => { + trace!("handling hard"); return core::build_steps::format::format( &builder::Builder::new(self), *check, @@ -564,22 +579,35 @@ impl Build { _ => (), } + trace!(cmd = ?self.config.cmd, "command is not hardcoded, continuing"); + if !self.config.dry_run() { - { + trace!("not a dry-run"); + + info_span!("[DRY RUN]").in_scope(|| { + trace!("executing dry-run sanity-check"); + // We first do a dry-run. This is a sanity-check to ensure that // steps don't do anything expensive in the dry-run. self.config.dry_run = DryRun::SelfCheck; let builder = builder::Builder::new(self); builder.execute_cli(); - } - self.config.dry_run = DryRun::Disabled; - let builder = builder::Builder::new(self); - builder.execute_cli(); + }); + + info_span!("[REAL RUN]").in_scope(|| { + trace!("executing real run"); + + self.config.dry_run = DryRun::Disabled; + let builder = builder::Builder::new(self); + builder.execute_cli(); + }); } else { let builder = builder::Builder::new(self); builder.execute_cli(); } + trace!("checking for postponed failures from `test --no-fail-fast`"); + // Check for postponed failures from `test --no-fail-fast`. let failures = self.delayed_failures.borrow(); if failures.len() > 0 {