Rollup merge of rust-lang#49089 - alexcrichton:fix-timings, r=Mark-Simulacrum

rustbuild: Tweak where timing information goes

This commit tweaks where timing and step information is printed out as part of
the build, ensuring that we do it as close to the location where work happens as
possible. In rustbuild various functions may perform long blocking work as
dependencies are assembled, so if we print out timing information early on we
may accidentally time more than just the step we were intending to time!

Author: kennytm

src/bootstrap/check.rs

@@ -40,17 +40,18 @@ impl Step for Std {
         let target = self.target;
         let compiler = builder.compiler(0, build.build);
 
-        let _folder = build.fold_output(|| format!("stage{}-std", compiler.stage));
-        println!("Checking std artifacts ({} -> {})", &compiler.host, target);
-
         let out_dir = build.stage_out(compiler, Mode::Libstd);
         build.clear_if_dirty(&out_dir, &builder.rustc(compiler));
         let mut cargo = builder.cargo(compiler, Mode::Libstd, target, "check");
         std_cargo(builder, &compiler, target, &mut cargo);
+
+        let _folder = build.fold_output(|| format!("stage{}-std", compiler.stage));
+        println!("Checking std artifacts ({} -> {})", &compiler.host, target);
         run_cargo(build,
                   &mut cargo,
                   &libstd_stamp(build, compiler, target),
                   true);
+
         let libdir = builder.sysroot_libdir(compiler, target);
         add_to_sysroot(&libdir, &libstd_stamp(build, compiler, target));
     }
@@ -86,19 +87,20 @@ impl Step for Rustc {
         let compiler = builder.compiler(0, build.build);
         let target = self.target;
 
-        let _folder = build.fold_output(|| format!("stage{}-rustc", compiler.stage));
-        println!("Checking compiler artifacts ({} -> {})", &compiler.host, target);
-
         let stage_out = builder.stage_out(compiler, Mode::Librustc);
         build.clear_if_dirty(&stage_out, &libstd_stamp(build, compiler, target));
         build.clear_if_dirty(&stage_out, &libtest_stamp(build, compiler, target));
 
         let mut cargo = builder.cargo(compiler, Mode::Librustc, target, "check");
         rustc_cargo(build, &mut cargo);
+
+        let _folder = build.fold_output(|| format!("stage{}-rustc", compiler.stage));
+        println!("Checking compiler artifacts ({} -> {})", &compiler.host, target);
         run_cargo(build,
                   &mut cargo,
                   &librustc_stamp(build, compiler, target),
                   true);
+
         let libdir = builder.sysroot_libdir(compiler, target);
         add_to_sysroot(&libdir, &librustc_stamp(build, compiler, target));
     }
@@ -128,16 +130,18 @@ impl Step for Test {
         let target = self.target;
         let compiler = builder.compiler(0, build.build);
 
-        let _folder = build.fold_output(|| format!("stage{}-test", compiler.stage));
-        println!("Checking test artifacts ({} -> {})", &compiler.host, target);
         let out_dir = build.stage_out(compiler, Mode::Libtest);
         build.clear_if_dirty(&out_dir, &libstd_stamp(build, compiler, target));
         let mut cargo = builder.cargo(compiler, Mode::Libtest, target, "check");
         test_cargo(build, &compiler, target, &mut cargo);
+
+        let _folder = build.fold_output(|| format!("stage{}-test", compiler.stage));
+        println!("Checking test artifacts ({} -> {})", &compiler.host, target);
         run_cargo(build,
                   &mut cargo,
                   &libtest_stamp(build, compiler, target),
                   true);
+
         let libdir = builder.sysroot_libdir(compiler, target);
         add_to_sysroot(&libdir, &libtest_stamp(build, compiler, target));
     }

src/bootstrap/compile.rs

@@ -93,10 +93,6 @@ impl Step for Std {
             return;
         }
 
-        let _folder = build.fold_output(|| format!("stage{}-std", compiler.stage));
-        println!("Building stage{} std artifacts ({} -> {})", compiler.stage,
-                &compiler.host, target);
-
         if target.contains("musl") {
             let libdir = builder.sysroot_libdir(compiler, target);
             copy_musl_third_party_objects(build, target, &libdir);
@@ -106,6 +102,10 @@ impl Step for Std {
         build.clear_if_dirty(&out_dir, &builder.rustc(compiler));
         let mut cargo = builder.cargo(compiler, Mode::Libstd, target, "build");
         std_cargo(builder, &compiler, target, &mut cargo);
+
+        let _folder = build.fold_output(|| format!("stage{}-std", compiler.stage));
+        println!("Building stage{} std artifacts ({} -> {})", compiler.stage,
+                &compiler.host, target);
         run_cargo(build,
                   &mut cargo,
                   &libstd_stamp(build, compiler, target),
@@ -360,13 +360,14 @@ impl Step for Test {
             return;
         }
 
-        let _folder = build.fold_output(|| format!("stage{}-test", compiler.stage));
-        println!("Building stage{} test artifacts ({} -> {})", compiler.stage,
-                &compiler.host, target);
         let out_dir = build.stage_out(compiler, Mode::Libtest);
         build.clear_if_dirty(&out_dir, &libstd_stamp(build, compiler, target));
         let mut cargo = builder.cargo(compiler, Mode::Libtest, target, "build");
         test_cargo(build, &compiler, target, &mut cargo);
+
+        let _folder = build.fold_output(|| format!("stage{}-test", compiler.stage));
+        println!("Building stage{} test artifacts ({} -> {})", compiler.stage,
+                &compiler.host, target);
         run_cargo(build,
                   &mut cargo,
                   &libtest_stamp(build, compiler, target),
@@ -482,16 +483,16 @@ impl Step for Rustc {
             target: build.build,
         });
 
-        let _folder = build.fold_output(|| format!("stage{}-rustc", compiler.stage));
-        println!("Building stage{} compiler artifacts ({} -> {})",
-                 compiler.stage, &compiler.host, target);
-
         let stage_out = builder.stage_out(compiler, Mode::Librustc);
         build.clear_if_dirty(&stage_out, &libstd_stamp(build, compiler, target));
         build.clear_if_dirty(&stage_out, &libtest_stamp(build, compiler, target));
 
         let mut cargo = builder.cargo(compiler, Mode::Librustc, target, "build");
         rustc_cargo(build, &mut cargo);
+
+        let _folder = build.fold_output(|| format!("stage{}-rustc", compiler.stage));
+        println!("Building stage{} compiler artifacts ({} -> {})",
+                 compiler.stage, &compiler.host, target);
         run_cargo(build,
                   &mut cargo,
                   &librustc_stamp(build, compiler, target),
@@ -634,8 +635,6 @@ impl Step for CodegenBackend {
             .arg(build.src.join("src/librustc_trans/Cargo.toml"));
         rustc_cargo_env(build, &mut cargo);
 
-        let _folder = build.fold_output(|| format!("stage{}-rustc_trans", compiler.stage));
-
         match &*self.backend {
             "llvm" | "emscripten" => {
                 // Build LLVM for our target. This will implicitly build the
@@ -685,6 +684,8 @@ impl Step for CodegenBackend {
 
         let tmp_stamp = build.cargo_out(compiler, Mode::Librustc, target)
             .join(".tmp.stamp");
+
+        let _folder = build.fold_output(|| format!("stage{}-rustc_trans", compiler.stage));
         let files = run_cargo(build,
                               cargo.arg("--features").arg(features),
                               &tmp_stamp,

src/bootstrap/test.rs

@@ -530,8 +530,6 @@ impl Step for Tidy {
     fn run(self, builder: &Builder) {
         let build = builder.build;
 
-        let _folder = build.fold_output(|| "tidy");
-        println!("tidy check");
         let mut cmd = builder.tool_cmd(Tool::Tidy);
         cmd.arg(build.src.join("src"));
         cmd.arg(&build.initial_cargo);
@@ -541,6 +539,9 @@ impl Step for Tidy {
         if build.config.quiet_tests {
             cmd.arg("--quiet");
         }
+
+        let _folder = build.fold_output(|| "tidy");
+        println!("tidy check");
         try_run(build, &mut cmd);
     }
 
@@ -841,9 +842,6 @@ impl Step for Compiletest {
         builder.ensure(native::TestHelpers { target });
         builder.ensure(RemoteCopyLibs { compiler, target });
 
-        let _folder = build.fold_output(|| format!("test_{}", suite));
-        println!("Check compiletest suite={} mode={} ({} -> {})",
-                 suite, mode, &compiler.host, target);
         let mut cmd = builder.tool_cmd(Tool::Compiletest);
 
         // compiletest currently has... a lot of arguments, so let's just pass all
@@ -1003,6 +1001,9 @@ impl Step for Compiletest {
 
         build.ci_env.force_coloring_in_ci(&mut cmd);
 
+        let _folder = build.fold_output(|| format!("test_{}", suite));
+        println!("Check compiletest suite={} mode={} ({} -> {})",
+                 suite, mode, &compiler.host, target);
         let _time = util::timeit();
         try_run(build, &mut cmd);
     }
@@ -1147,20 +1148,21 @@ impl Step for ErrorIndex {
 
         builder.ensure(compile::Std { compiler, target: compiler.host });
 
-        let _folder = build.fold_output(|| "test_error_index");
-        println!("Testing error-index stage{}", compiler.stage);
-
         let dir = testdir(build, compiler.host);
         t!(fs::create_dir_all(&dir));
         let output = dir.join("error-index.md");
 
-        let _time = util::timeit();
-        build.run(builder.tool_cmd(Tool::ErrorIndex)
-                    .arg("markdown")
-                    .arg(&output)
-                    .env("CFG_BUILD", &build.build)
-                    .env("RUSTC_ERROR_METADATA_DST", build.extended_error_dir()));
+        let mut tool = builder.tool_cmd(Tool::ErrorIndex);
+        tool.arg("markdown")
+            .arg(&output)
+            .env("CFG_BUILD", &build.build)
+            .env("RUSTC_ERROR_METADATA_DST", build.extended_error_dir());
+
 
+        let _folder = build.fold_output(|| "test_error_index");
+        println!("Testing error-index stage{}", compiler.stage);
+        let _time = util::timeit();
+        build.run(&mut tool);
         markdown_test(builder, compiler, &output);
     }
 }
@@ -1405,11 +1407,6 @@ impl Step for Crate {
             }
             _ => panic!("can only test libraries"),
         };
-        let _folder = build.fold_output(|| {
-            format!("{}_stage{}-{}", test_kind.subcommand(), compiler.stage, krate)
-        });
-        println!("{} {} stage{} ({} -> {})", test_kind, krate, compiler.stage,
-                &compiler.host, target);
 
         // Build up the base `cargo test` command.
         //
@@ -1441,8 +1438,6 @@ impl Step for Crate {
             cargo.arg("--quiet");
         }
 
-        let _time = util::timeit();
-
         if target.contains("emscripten") {
             cargo.env(format!("CARGO_TARGET_{}_RUNNER", envify(&target)),
                       build.config.nodejs.as_ref().expect("nodejs not configured"));
@@ -1470,6 +1465,13 @@ impl Step for Crate {
                       format!("{} run",
                               builder.tool_exe(Tool::RemoteTestClient).display()));
         }
+
+        let _folder = build.fold_output(|| {
+            format!("{}_stage{}-{}", test_kind.subcommand(), compiler.stage, krate)
+        });
+        println!("{} {} stage{} ({} -> {})", test_kind, krate, compiler.stage,
+                &compiler.host, target);
+        let _time = util::timeit();
         try_run(build, &mut cargo);
     }
 }
@@ -1518,12 +1520,6 @@ impl Step for CrateRustdoc {
                                                  target,
                                                  test_kind.subcommand(),
                                                  "src/tools/rustdoc");
-        let _folder = build.fold_output(|| {
-            format!("{}_stage{}-rustdoc", test_kind.subcommand(), compiler.stage)
-        });
-        println!("{} rustdoc stage{} ({} -> {})", test_kind, compiler.stage,
-                &compiler.host, target);
-
         if test_kind.subcommand() == "test" && !build.fail_fast {
             cargo.arg("--no-fail-fast");
         }
@@ -1537,6 +1533,11 @@ impl Step for CrateRustdoc {
             cargo.arg("--quiet");
         }
 
+        let _folder = build.fold_output(|| {
+            format!("{}_stage{}-rustdoc", test_kind.subcommand(), compiler.stage)
+        });
+        println!("{} rustdoc stage{} ({} -> {})", test_kind, compiler.stage,
+                &compiler.host, target);
         let _time = util::timeit();
 
         try_run(build, &mut cargo);

src/bootstrap/tool.rs

@@ -112,11 +112,11 @@ impl Step for ToolBuild {
             Mode::Tool => panic!("unexpected Mode::Tool for tool build")
         }
 
-        let _folder = build.fold_output(|| format!("stage{}-{}", compiler.stage, tool));
-        println!("Building stage{} tool {} ({})", compiler.stage, tool, target);
-
         let mut cargo = prepare_tool_cargo(builder, compiler, target, "build", path);
         cargo.arg("--features").arg(self.extra_features.join(" "));
+
+        let _folder = build.fold_output(|| format!("stage{}-{}", compiler.stage, tool));
+        println!("Building stage{} tool {} ({})", compiler.stage, tool, target);
         let is_expected = build.try_run(&mut cargo);
         build.save_toolstate(tool, if is_expected {
             ToolState::TestFail
@@ -339,9 +339,6 @@ impl Step for Rustdoc {
 
         builder.ensure(compile::Rustc { compiler: build_compiler, target });
 
-        let _folder = build.fold_output(|| format!("stage{}-rustdoc", target_compiler.stage));
-        println!("Building rustdoc for stage{} ({})", target_compiler.stage, target_compiler.host);
-
         let mut cargo = prepare_tool_cargo(builder,
                                            build_compiler,
                                            target,
@@ -352,7 +349,10 @@ impl Step for Rustdoc {
         cargo.env("RUSTC_DEBUGINFO", builder.config.rust_debuginfo.to_string())
              .env("RUSTC_DEBUGINFO_LINES", builder.config.rust_debuginfo_lines.to_string());
 
+        let _folder = build.fold_output(|| format!("stage{}-rustdoc", target_compiler.stage));
+        println!("Building rustdoc for stage{} ({})", target_compiler.stage, target_compiler.host);
         build.run(&mut cargo);
+
         // Cargo adds a number of paths to the dylib search path on windows, which results in
         // the wrong rustdoc being executed. To avoid the conflicting rustdocs, we name the "tool"
         // rustdoc a different name.