Rollup merge of #145261 - Kobzol:bootstrap-tracing, r=jieyouxu

Improve tracing in bootstrap

I was annoyed that bootstrap had like 5 separate ways of debugging/tracing/profiling, and it was hard for me to understand how are individual steps executed. This PR tries to unify severla things behind `BOOTSTRAP_TRACING`, and improve tracing/profiling in general:
- All generated tracing outputs are now stored in a single directory to make it easier to examine them, plus bootstrap prepares a `latest` symlink to the latest generated tracing output directory for convenience.
- All executed spans are now logged automatically (without requiring usage of `#[tracing::instrument]`).
- A custom span/event formatter was implemented, to provide domain-specific output (like location of executed commands or spans) and hopefully also to reduce visual clutter.
  - `tracing_forest` was removed. While it did some useful postprocessing, it didn't expose enough information for making the dynamic step spans work.
- You can now explicitly log steps (`STEP=info`) and/or commands (`COMMAND=info`), to have more granular control over what gets logged.
- `print-step-timings` also show when a step starts its execution (not just when it ends it), so that when some step fails in CI, we can actually see what step it was (before we would only see the end of the previous step).
- The rustc-dev-guide page on debugging/profiling bootstrap was updated.

There are still some things that work outside of tracing (`print-step-timings` and `dump-bootstrap-shims`), but I think that for now this improvement is good enough.

I removed the `> step`, `< step` verbose output, because I found it unusable, as verbose bootstrap output also enables verbose Cargo output, and then you simply drown in too much data, and because I think that the new tracing system makes it obsolete (although it does require recompilation with the `tracing` feature). If you want to keep it, happy to revert 690c781475acb890f33d928186bdaea9ef179330. And the information about cached steps is now also shown in the Graphviz step dependency graph.

We can modify the tracing output however we want, as we now implement it ourselves. Notably, we could also show exit logs for step spans, currently I only show enter spans. Maybe creating indents for each executed nested command is also not needed. Happy to hear feedback!

Some further improvements could be to print step durations, if we decide to also log step exit events. We could also try to enable tracing in CI logs, but it might be too verbose.

Best reviewed commit-by-commit.

r? ``@jieyouxu``

CC ``@Shourya742``

12 files changed, 511 insertions, 313 deletions

diff --git a/src/bootstrap/Cargo.lock b/src/bootstrap/Cargo.lock
index 044d360ac37..537f4b6184f 100644
--- a/src/bootstrap/Cargo.lock
+++ b/src/bootstrap/Cargo.lock
@@ -12,21 +12,18 @@ dependencies = [
 ]
 
 [[package]]
-name = "ansi_term"
-version = "0.12.1"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2"
-dependencies = [
- "winapi",
-]
-
-[[package]]
 name = "anstyle"
 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"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -47,6 +44,7 @@ version = "0.0.0"
 dependencies = [
  "build_helper",
  "cc",
+ "chrono",
  "clap",
  "clap_complete",
  "cmake",
@@ -71,7 +69,6 @@ dependencies = [
  "toml",
  "tracing",
  "tracing-chrome",
- "tracing-forest",
  "tracing-subscriber",
  "walkdir",
  "windows",
@@ -113,6 +110,15 @@ 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 = [
+ "num-traits",
+]
+
+[[package]]
 name = "clap"
 version = "4.5.20"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -459,6 +465,15 @@ dependencies = [
 ]
 
 [[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"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -776,26 +791,6 @@ dependencies = [
 ]
 
 [[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"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -858,19 +853,6 @@ dependencies = [
 ]
 
 [[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"
 source = "registry+https://github.com/rust-lang/crates.io-index"
diff --git a/src/bootstrap/Cargo.toml b/src/bootstrap/Cargo.toml
index 60d4976b934..bdf0b42255e 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:chrono", "dep:tempfile"]
 
 [lib]
 path = "src/lib.rs"
@@ -61,10 +61,11 @@ xz2 = "0.1"
 sysinfo = { version = "0.37.0", default-features = false, optional = true, features = ["system"] }
 
 # Dependencies needed by the `tracing` feature
+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"] }
-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 cf24fedaebb..8b2d67266a7 100644
--- a/src/bootstrap/src/bin/main.rs
+++ b/src/bootstrap/src/bin/main.rs
@@ -7,6 +7,7 @@
 
 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};
@@ -15,19 +16,16 @@ use bootstrap::{
     Build, CONFIG_CHANGE_HISTORY, ChangeId, Config, Flags, Subcommand, debug,
     find_recent_config_change_ids, human_readable_changes, t,
 };
-#[cfg(feature = "tracing")]
-use tracing::instrument;
 
-fn is_bootstrap_profiling_enabled() -> bool {
-    env::var("BOOTSTRAP_PROFILE").is_ok_and(|v| v == "1")
+fn is_tracing_enabled() -> bool {
+    cfg!(feature = "tracing")
 }
 
-#[cfg_attr(feature = "tracing", instrument(level = "trace", name = "main"))]
 fn main() {
     #[cfg(feature = "tracing")]
-    let _guard = setup_tracing();
+    let guard = bootstrap::setup_tracing("BOOTSTRAP_TRACING");
 
-    let start_time = Instant::now();
+    let _start_time = Instant::now();
 
     let args = env::args().skip(1).collect::<Vec<_>>();
 
@@ -102,6 +100,35 @@ fn main() {
     let dump_bootstrap_shims = config.dump_bootstrap_shims;
     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);
+
+        #[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");
     let mut build = Build::new(config);
     build.build();
@@ -156,12 +183,13 @@ fn main() {
         }
     }
 
-    if is_bootstrap_profiling_enabled() {
-        build.report_summary(start_time);
-    }
-
     #[cfg(feature = "tracing")]
-    build.report_step_graph();
+    {
+        build.report_summary(&tracing_dir.join("command-stats.txt"), _start_time);
+        build.report_step_graph(&tracing_dir);
+        guard.copy_to_dir(&tracing_dir);
+        eprintln!("Tracing/profiling output has been written to {}", latest_trace_dir.display());
+    }
 }
 
 fn check_version(config: &Config) -> Option<String> {
@@ -219,37 +247,3 @@ fn check_version(config: &Config) -> Option<String> {
 
     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() -> impl Drop {
-    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);
-
-    // Writes the Chrome profile to trace-<unix-timestamp>.json if enabled
-    if !is_bootstrap_profiling_enabled() {
-        chrome_layer = chrome_layer.writer(io::sink());
-    }
-
-    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).unwrap();
-    _guard
-}
diff --git a/src/bootstrap/src/core/build_steps/compile.rs b/src/bootstrap/src/core/build_steps/compile.rs
index 2a236de0192..790a5be25bd 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, GccOutput, 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;
 
@@ -717,19 +703,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;
@@ -895,15 +868,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;
@@ -1033,15 +997,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;
@@ -1517,19 +1472,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;
@@ -1571,17 +1513,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();
@@ -1656,17 +1587,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();
@@ -1841,15 +1761,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);
@@ -2025,15 +1936,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;
 
@@ -2592,7 +2494,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/build_steps/llvm.rs b/src/bootstrap/src/core/build_steps/llvm.rs
index 16941a32bb1..aab2b634c43 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 f1be0af3183..075f9743a4a 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 793e6b629c9..cf5a0325e5c 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};
@@ -415,14 +412,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 {
@@ -901,15 +890,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 {
@@ -1002,15 +982,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,
@@ -1207,10 +1178,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,
diff --git a/src/bootstrap/src/core/builder/mod.rs b/src/bootstrap/src/core/builder/mod.rs
index 54bf1842ab3..31f818745fb 100644
--- a/src/bootstrap/src/core/builder/mod.rs
+++ b/src/bootstrap/src/core/builder/mod.rs
@@ -951,6 +951,9 @@ impl Step for Libdir {
     }
 }
 
+#[cfg(feature = "tracing")]
+pub const STEP_SPAN_TARGET: &str = "STEP";
+
 impl<'a> Builder<'a> {
     fn get_step_descriptions(kind: Kind) -> Vec<StepDescription> {
         macro_rules! describe {
@@ -1680,8 +1683,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() {
@@ -1691,7 +1692,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")]
             {
@@ -1706,10 +1706,29 @@ 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);
+
+            #[cfg(feature = "tracing")]
+            let _span = {
+                // Keep the target and field names synchronized with `setup_tracing`.
+                let span = tracing::info_span!(
+                    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",
+                    step_name = pretty_step_name::<S>(),
+                    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);
@@ -1717,13 +1736,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::<S>();
             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()
             );
@@ -1737,7 +1752,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
     }
@@ -1810,6 +1824,25 @@ 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`.
+pub fn pretty_step_name<S: Step>() -> String {
+    // Normalize step type path to only keep the module and the type name
+    let path = type_name::<S>().rsplit("::").take(2).collect::<Vec<_>>();
+    path.into_iter().rev().collect::<Vec<_>>().join("::")
+}
+
+/// Renders `step` using its `Debug` implementation and extract the field arguments out of it.
+fn step_debug_args<S: Step>(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()
+}
+
+fn pretty_print_step<S: Step>(step: &S) -> String {
+    format!("{} {{ {} }}", pretty_step_name::<S>(), step_debug_args(step))
+}
+
 impl<'a> AsRef<ExecutionContext> for Builder<'a> {
     fn as_ref(&self) -> &ExecutionContext {
         self.exec_ctx()
diff --git a/src/bootstrap/src/lib.rs b/src/bootstrap/src/lib.rs
index 0b65ebc0671..706a3cbb210 100644
--- a/src/bootstrap/src/lib.rs
+++ b/src/bootstrap/src/lib.rs
@@ -37,14 +37,14 @@ 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;
 
 pub use core::builder::PathSet;
+#[cfg(feature = "tracing")]
+pub use core::builder::STEP_SPAN_TARGET;
 pub use core::config::flags::{Flags, Subcommand};
 pub use core::config::{ChangeId, Config};
 
@@ -53,7 +53,9 @@ 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};
+#[cfg(feature = "tracing")]
+pub use utils::tracing::setup_tracing;
 
 use crate::core::build_steps::vendor::VENDOR_DIR;
 
@@ -2005,13 +2007,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 03760faec69..9a536f75ab7 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,8 @@ 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)]
@@ -77,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(|| "<unknown command>".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();
@@ -121,17 +126,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 +218,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}");
     }
 }
 
@@ -686,9 +681,6 @@ impl ExecutionContext {
     ) -> DeferredCommand<'a> {
         let fingerprint = command.fingerprint();
 
-        #[cfg(feature = "tracing")]
-        let span_guard = trace_cmd!(command);
-
         if let Some(cached_output) = self.command_cache.get(&fingerprint) {
             command.mark_as_executed();
             self.verbose(|| println!("Cache hit: {command:?}"));
@@ -696,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();
 
@@ -779,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/step_graph.rs b/src/bootstrap/src/utils/step_graph.rs
index c45825a4222..cffe0dbb3e3 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::core::builder::{AnyDebug, Step, pretty_step_name};
+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.
@@ -41,13 +43,7 @@ impl StepGraph {
                 metadata.get_target()
             )
         } else {
-            let type_name = std::any::type_name::<S>();
-            type_name
-                .strip_prefix("bootstrap::core::")
-                .unwrap_or(type_name)
-                .strip_prefix("build_steps::")
-                .unwrap_or(type_name)
-                .to_string()
+            pretty_step_name::<S>()
         };
 
         let node = Node { label, tooltip: node_key.clone() };
@@ -80,10 +76,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 +143,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)?);
diff --git a/src/bootstrap/src/utils/tracing.rs b/src/bootstrap/src/utils/tracing.rs
index 109407bc5f2..428ba013c98 100644
--- a/src/bootstrap/src/utils/tracing.rs
+++ b/src/bootstrap/src/utils/tracing.rs
@@ -48,17 +48,369 @@ macro_rules! error {
     }
 }
 
-#[macro_export]
-macro_rules! trace_cmd {
-    ($cmd:expr) => {
+#[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();
+    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,
+        location
+    )
+    .entered()
+}
+
+// # 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_SPAN_TARGET;
+    use crate::utils::tracing::COMMAND_SPAN_TARGET;
+
+    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());
+
+        // 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::<StepNameExtension>()
+                    {
+                        extension.0.clone()
+                    } else if s.metadata().target() == COMMAND_SPAN_TARGET
+                        && let Some(extension) = s.extensions().get::<CommandNameExtension>()
+                    {
+                        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();
+        TracingGuard { guard, _tempdir: tempdir, chrome_tracing_path }
+    }
+
+    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<String>,
+        /// Name of a recorded psna
+        step_name: Option<String>,
+        /// Short name of an executed command
+        cmd_name: Option<String>,
+        /// 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());
+                }
+                "cmd_name" => {
+                    self.cmd_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 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,
+        span_values: std::sync::Mutex<std::collections::HashMap<tracing::Id, FieldValues>>,
+    }
+
+    impl TracingPrinter {
+        fn format_header<W: Write>(
+            &self,
+            writer: &mut W,
+            time: DateTime<Utc>,
+            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<W: Write>(&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<W: Write, S>(
+            &self,
+            writer: &mut W,
+            span: SpanRef<'_, S>,
+            field_values: Option<&FieldValues>,
+            action: SpanAction,
+        ) -> std::io::Result<()>
+        where
+            S: for<'lookup> LookupSpan<'lookup>,
         {
-            ::tracing::span!(
-                target: "COMMAND",
-                ::tracing::Level::TRACE,
-                "executing command",
-                cmd = $cmd.fingerprint().format_short_cmd(),
-                full_cmd = ?$cmd
-            ).entered()
+            let now = Utc::now();
+
+            self.format_header(writer, now, span.metadata().level())?;
+            match action {
+                SpanAction::Enter => {
+                    write!(writer, "> ")?;
+                }
+            }
+
+            fn write_fields<'a, I: IntoIterator<Item = &'a (&'a str, String)>, W: Write>(
+                writer: &mut W,
+                iter: I,
+            ) -> std::io::Result<()> {
+                let items = iter.into_iter().collect::<Vec<_>>();
+                if !items.is_empty() {
+                    write!(writer, " [")?;
+                    for (index, (name, value)) in items.iter().enumerate() {
+                        write!(writer, "{name} = {value}")?;
+                        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())?;
+                }
+            }
+
+            writeln!(writer)?;
+            Ok(())
         }
-    };
+    }
+
+    fn write_location<W: Write>(
+        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::<Vec<_>>()
+                .into_iter()
+                .rev()
+                .collect();
+
+            write!(writer, " ({}", filename.display())?;
+            if let Some(line) = metadata.line() {
+                write!(writer, ":{line}")?;
+            }
+            write!(writer, ")")?;
+        }
+        Ok(())
+    }
+
+    impl<S> Layer<S> 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 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);
+        }
+
+        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;