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!

src/bootstrap/check.rs

@@ -40,17 +40,18 @@ fn run(self, builder: &Builder) {
         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 @@ fn run(self, builder: &Builder) {
         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 @@ fn run(self, builder: &Builder) {
         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 @@ fn run(self, builder: &Builder) {
             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 @@ fn run(self, builder: &Builder) {
         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 @@ fn run(self, builder: &Builder) {
             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 @@ fn run(self, builder: &Builder) {
             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 @@ fn run(self, builder: &Builder) {
             .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 @@ fn run(self, builder: &Builder) {
 
         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 @@ fn run(self, builder: &Builder) {
         if build.config.quiet_tests {
             cmd.arg("--quiet");
         }
+
+        let _folder = build.fold_output(|| "tidy");
+        println!("tidy check");
         try_run(build, &mut cmd);
     }
 
@@ -836,9 +837,6 @@ fn run(self, builder: &Builder) {
         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
@@ -998,6 +996,9 @@ fn run(self, builder: &Builder) {
 
         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);
     }
@@ -1142,20 +1143,21 @@ fn run(self, builder: &Builder) {
 
         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);
     }
 }
@@ -1400,11 +1402,6 @@ fn run(self, builder: &Builder) {
             }
             _ => 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.
         //
@@ -1436,8 +1433,6 @@ fn run(self, builder: &Builder) {
             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"));
@@ -1465,6 +1460,13 @@ fn run(self, builder: &Builder) {
                       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);
     }
 }
@@ -1513,12 +1515,6 @@ fn run(self, builder: &Builder) {
                                                  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");
         }
@@ -1532,6 +1528,11 @@ fn run(self, builder: &Builder) {
             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 @@ fn run(self, builder: &Builder) -> Option<PathBuf> {
             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 @@ fn run(self, builder: &Builder) -> PathBuf {
 
         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 @@ fn run(self, builder: &Builder) -> PathBuf {
         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.