bootstrap: add more tracing to compiler/std/llvm flows

Author: jieyouxu

src/bootstrap/src/core/build_steps/compile.rs

@@ -16,6 +16,8 @@ use std::{env, fs};
 
 use object::BinaryFormat;
 use object::read::archive::ArchiveFile;
+#[cfg(feature = "tracing")]
+use tracing::instrument;
 
 use crate::core::build_steps::doc::DocumentationFormat;
 use crate::core::build_steps::tool::{self, Tool};
@@ -30,7 +32,7 @@ use crate::utils::helpers::{
     exe, is_dylib, move_file, t, target_supports_cranelift_backend, timeit,
 };
 use crate::utils::tarball::{GeneratedTarball, OverlayKind, Tarball};
-use crate::{Compiler, DependencyType, LLVM_TOOLS, Mode};
+use crate::{Compiler, DependencyType, LLVM_TOOLS, Mode, trace};
 
 pub fn pkgname(builder: &Builder<'_>, component: &str) -> String {
     format!("{}-{}", component, builder.rust_package_vers())
@@ -2029,6 +2031,15 @@ fn install_llvm_file(
 /// Maybe add LLVM object files to the given destination lib-dir. Allows either static or dynamic linking.
 ///
 /// Returns whether the files were actually copied.
+#[cfg_attr(
+    feature = "tracing",
+    instrument(
+        level = "trace",
+        name = "maybe_install_llvm",
+        skip_all,
+        fields(target = ?target, dst_libdir = ?dst_libdir, install_symlink = install_symlink),
+    ),
+)]
 fn maybe_install_llvm(
     builder: &Builder<'_>,
     target: TargetSelection,
@@ -2052,6 +2063,7 @@ fn maybe_install_llvm(
     // If the LLVM is coming from ourselves (just from CI) though, we
     // still want to install it, as it otherwise won't be available.
     if builder.is_system_llvm(target) {
+        trace!("system LLVM requested, no install");
         return false;
     }
 
@@ -2070,6 +2082,7 @@ fn maybe_install_llvm(
     } else if let llvm::LlvmBuildStatus::AlreadyBuilt(llvm::LlvmResult { llvm_config, .. }) =
         llvm::prebuilt_llvm_config(builder, target, true)
     {
+        trace!("LLVM already built, installing LLVM files");
         let mut cmd = command(llvm_config);
         cmd.arg("--libfiles");
         builder.verbose(|| println!("running {cmd:?}"));
@@ -2092,6 +2105,19 @@ fn maybe_install_llvm(
 }
 
 /// Maybe add libLLVM.so to the target lib-dir for linking.
+#[cfg_attr(
+    feature = "tracing",
+    instrument(
+        level = "trace",
+        name = "maybe_install_llvm_target",
+        skip_all,
+        fields(
+            llvm_link_shared = ?builder.llvm_link_shared(),
+            target = ?target,
+            sysroot = ?sysroot,
+        ),
+    ),
+)]
 pub fn maybe_install_llvm_target(builder: &Builder<'_>, target: TargetSelection, sysroot: &Path) {
     let dst_libdir = sysroot.join("lib/rustlib").join(target).join("lib");
     // We do not need to copy LLVM files into the sysroot if it is not
@@ -2103,6 +2129,19 @@ pub fn maybe_install_llvm_target(builder: &Builder<'_>, target: TargetSelection,
 }
 
 /// Maybe add libLLVM.so to the runtime lib-dir for rustc itself.
+#[cfg_attr(
+    feature = "tracing",
+    instrument(
+        level = "trace",
+        name = "maybe_install_llvm_runtime",
+        skip_all,
+        fields(
+            llvm_link_shared = ?builder.llvm_link_shared(),
+            target = ?target,
+            sysroot = ?sysroot,
+        ),
+    ),
+)]
 pub fn maybe_install_llvm_runtime(builder: &Builder<'_>, target: TargetSelection, sysroot: &Path) {
     let dst_libdir =
         sysroot.join(builder.sysroot_libdir_relative(Compiler { stage: 1, host: target }));

src/bootstrap/src/core/build_steps/dist.rs

@@ -16,6 +16,8 @@ use std::{env, fs};
 
 use build_helper::ci::CiEnv;
 use build_helper::git::get_closest_merge_commit;
+#[cfg(feature = "tracing")]
+use tracing::instrument;
 
 use crate::core::builder::{Builder, RunConfig, ShouldRun, Step};
 use crate::core::config::{Config, TargetSelection};
@@ -24,7 +26,7 @@ use crate::utils::exec::command;
 use crate::utils::helpers::{
     self, exe, get_clang_cl_resource_dir, t, unhashed_basename, up_to_date,
 };
-use crate::{CLang, GitRepo, Kind};
+use crate::{CLang, GitRepo, Kind, trace};
 
 #[derive(Clone)]
 pub struct LlvmResult {
@@ -934,6 +936,15 @@ 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",
@@ -959,7 +970,9 @@ impl Step for Enzyme {
         let out_dir = builder.enzyme_out(target);
         let stamp = BuildStamp::new(&out_dir).with_prefix("enzyme").add_stamp(smart_stamp_hash);
 
+        trace!("checking build stamp to see if we need to rebuild enzyme artifacts");
         if stamp.is_up_to_date() {
+            trace!(?out_dir, "enzyme build artifacts are up to date");
             if stamp.stamp().is_empty() {
                 builder.info(
                     "Could not determine the Enzyme submodule commit hash. \
@@ -973,6 +986,7 @@ impl Step for Enzyme {
             return out_dir;
         }
 
+        trace!(?target, "(re)building enzyme artifacts");
         builder.info(&format!("Building Enzyme for {}", target));
         t!(stamp.remove());
         let _time = helpers::timeit(builder);
@@ -994,6 +1008,7 @@ impl Step for Enzyme {
             (true, false) => "Release",
             (true, true) => "RelWithDebInfo",
         };
+        trace!(?profile);
 
         cfg.out_dir(&out_dir)
             .profile(profile)

src/bootstrap/src/core/build_steps/llvm.rs

@@ -1,6 +1,9 @@
 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};
@@ -304,6 +307,14 @@ macro_rules! bootstrap_tool {
                 });
             }
 
+            #[cfg_attr(
+                feature = "tracing",
+                instrument(
+                    level = "debug",
+                    name = $tool_name,
+                    skip_all,
+                ),
+            )]
             fn run(self, builder: &Builder<'_>) -> PathBuf {
                 $(
                     for submodule in $submodules {
@@ -758,6 +769,15 @@ impl Step for LldWrapper {
         run.never()
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        instrument(
+            level = "debug",
+            name = "LldWrapper::run",
+            skip_all,
+            fields(build_compiler = ?self.build_compiler, target_compiler = ?self.target_compiler),
+        ),
+    )]
     fn run(self, builder: &Builder<'_>) {
         if builder.config.dry_run() {
             return;
@@ -914,6 +934,10 @@ impl Step for LlvmBitcodeLinker {
         });
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        instrument(level = "debug", name = "LlvmBitcodeLinker::run", skip_all)
+    )]
     fn run(self, builder: &Builder<'_>) -> PathBuf {
         let bin_name = "llvm-bitcode-linker";
 

src/bootstrap/src/core/build_steps/tool.rs

@@ -10,6 +10,8 @@ use std::time::{Duration, Instant};
 use std::{env, fs};
 
 use clap::ValueEnum;
+#[cfg(feature = "tracing")]
+use tracing::instrument;
 
 pub use self::cargo::{Cargo, cargo_profile_var};
 pub use crate::Compiler;
@@ -21,7 +23,7 @@ use crate::core::config::{DryRun, TargetSelection};
 use crate::utils::cache::Cache;
 use crate::utils::exec::{BootstrapCommand, command};
 use crate::utils::helpers::{self, LldThreads, add_dylib_path, exe, libdir, linker_args, t};
-use crate::{Build, Crate};
+use crate::{Build, Crate, trace};
 
 mod cargo;
 
@@ -1214,6 +1216,19 @@ impl<'a> Builder<'a> {
     /// compiler will run on, *not* the target it will build code for). Explicitly does not take
     /// `Compiler` since all `Compiler` instances are meant to be obtained through this function,
     /// since it ensures that they are valid (i.e., built and assembled).
+    #[cfg_attr(
+        feature = "tracing",
+        instrument(
+            level = "trace",
+            name = "Builder::compiler",
+            target = "COMPILER",
+            skip_all,
+            fields(
+                stage = stage,
+                host = ?host,
+            ),
+        ),
+    )]
     pub fn compiler(&self, stage: u32, host: TargetSelection) -> Compiler {
         self.ensure(compile::Assemble { target_compiler: Compiler { stage, host } })
     }
@@ -1229,19 +1244,39 @@ impl<'a> Builder<'a> {
     /// sysroot.
     ///
     /// See `force_use_stage1` and `force_use_stage2` for documentation on what each argument is.
+    #[cfg_attr(
+        feature = "tracing",
+        instrument(
+            level = "trace",
+            name = "Builder::compiler_for",
+            target = "COMPILER_FOR",
+            skip_all,
+            fields(
+                stage = stage,
+                host = ?host,
+                target = ?target,
+            ),
+        ),
+    )]
     pub fn compiler_for(
         &self,
         stage: u32,
         host: TargetSelection,
         target: TargetSelection,
     ) -> Compiler {
-        if self.build.force_use_stage2(stage) {
+        #![allow(clippy::let_and_return)]
+        let resolved_compiler = if self.build.force_use_stage2(stage) {
+            trace!(target: "COMPILER_FOR", ?stage, "force_use_stage2");
             self.compiler(2, self.config.build)
         } else if self.build.force_use_stage1(stage, target) {
+            trace!(target: "COMPILER_FOR", ?stage, "force_use_stage1");
             self.compiler(1, self.config.build)
         } else {
+            trace!(target: "COMPILER_FOR", ?stage, ?host, "no force, fallback to `compiler()`");
             self.compiler(stage, host)
-        }
+        };
+        trace!(target: "COMPILER_FOR", ?resolved_compiler);
+        resolved_compiler
     }
 
     pub fn sysroot(&self, compiler: Compiler) -> PathBuf {

src/bootstrap/src/core/builder/mod.rs

@@ -2747,6 +2747,15 @@ impl Config {
     /// tarball). Typically [`crate::Build::require_submodule`] should be
     /// used instead to provide a nice error to the user if the submodule is
     /// missing.
+    #[cfg_attr(
+        feature = "tracing",
+        instrument(
+            level = "trace",
+            name = "Config::update_submodule",
+            skip_all,
+            fields(relative_path = ?relative_path),
+        ),
+    )]
     pub(crate) fn update_submodule(&self, relative_path: &str) {
         if !self.submodules() {
             return;

src/bootstrap/src/core/config/config.rs

@@ -469,6 +469,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.
+    #[cfg_attr(
+        feature = "tracing",
+        instrument(
+            level = "trace",
+            name = "Build::require_submodule",
+            skip_all,
+            fields(submodule = 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.