Rollup merge of #82532 - pnkfelix:rustbuild-print-step-rusage, r=Mark-Simulacrum

Add `build.print_step_rusage` to config.toml

Adds `build.print_step_rusage` to config.toml, which is meant to be an easy way to let compiler developers get feedback on the terminal during bootstrap about resource usage during each step.

The output is piggy-backed on `[PRINT-STEP-TIMINGS]`, mostly because the functionality seemed to naturally fit there in the overall control-flow and output structure (even if very little is shared between the implementations themselves).

Some sample output (from my Linux box, where I believe the `max rss` output to be somewhat trust-worthy...):

```
[...]
   Compiling regex v1.4.3
[RUSTC-TIMING] tempfile test:false 0.323 user: 1.418662 sys: 0.81767 max rss (kb): 182084 page reclaims: 26615 page faults: 0 fs block inputs: 0 fs block outputs: 2160 voluntary ctxt switches: 798 involuntary ctxt switches: 131
   Completed tempfile v3.1.0 in 0.3s
[RUSTC-TIMING] chalk_ir test:false 1.890 user: 1.893603 sys: 0.99663 max rss (kb): 239432 page reclaims: 32107 page faults: 0 fs block inputs: 0 fs block outputs: 25008 voluntary ctxt switches: 108 involuntary ctxt switches: 183
   Completed chalk-ir v0.55.0 in 1.9s
   Compiling rustc_data_structures v0.0.0 (/home/pnkfelix/Dev/Rust/rust.git/compiler/rustc_data_structures)
[RUSTC-TIMING] chrono test:false 1.244 user: 3.333198 sys: 0.134963 max rss (kb): 246612 page reclaims: 44857 page faults: 0 fs block inputs: 0 fs block outputs: 11704 voluntary ctxt switches: 1043 involuntary ctxt switches: 326
   Completed chrono v0.4.15 in 1.3s
[RUSTC-TIMING] rustc_rayon test:false 1.332 user: 1.763912 sys: 0.75996 max rss (kb): 239076 page reclaims: 35285 page faults: 0 fs block inputs: 0 fs block outputs: 19576 voluntary ctxt switches: 359 involuntary ctxt switches: 168
   Completed rustc-rayon v0.3.0 in 1.3s
   Compiling matchers v0.0.1
[RUSTC-TIMING] matchers test:false 0.100 user: 0.94495 sys: 0.15119 max rss (kb): 140076 page reclaims: 8200 page faults: 0 fs block inputs: 0 fs block outputs: 392 voluntary ctxt switches: 43 involuntary ctxt switches: 12
   Completed matchers v0.0.1 in 0.1s
[...]
```

Author: JohnTitor

config.toml.example

@@ -290,6 +290,12 @@ changelog-seen = 2
 # tracking over time)
 #print-step-timings = false
 
+# Print out resource usage data for each rustbuild step, as defined by the Unix
+# struct rusage. (Note that this setting is completely unstable: the data it
+# captures, what platforms it supports, the format of its associated output, and
+# this setting's very existence, are all subject to change.)
+#print-step-rusage = false
+
 # =============================================================================
 # General install configuration options
 # =============================================================================

src/bootstrap/bin/rustc.rs

@@ -161,16 +161,24 @@ fn main() {
         cmd.status().expect(&errmsg)
     };
 
-    if env::var_os("RUSTC_PRINT_STEP_TIMINGS").is_some() {
+    if env::var_os("RUSTC_PRINT_STEP_TIMINGS").is_some()
+        || env::var_os("RUSTC_PRINT_STEP_RUSAGE").is_some()
+    {
         if let Some(crate_name) = crate_name {
             let dur = start.elapsed();
             let is_test = args.iter().any(|a| a == "--test");
+            // If the user requested resource usage data, then
+            // include that in addition to the timing output.
+            let rusage_data =
+                env::var_os("RUSTC_PRINT_STEP_RUSAGE").and_then(|_| format_rusage_data());
             eprintln!(
-                "[RUSTC-TIMING] {} test:{} {}.{:03}",
+                "[RUSTC-TIMING] {} test:{} {}.{:03}{}{}",
                 crate_name,
                 is_test,
                 dur.as_secs(),
-                dur.subsec_millis()
+                dur.subsec_millis(),
+                if rusage_data.is_some() { " " } else { "" },
+                rusage_data.unwrap_or(String::new()),
             );
         }
     }
@@ -198,3 +206,71 @@ fn main() {
         }
     }
 }
+
+#[cfg(not(unix))]
+/// getrusage is not available on non-unix platforms. So for now, we do not
+/// bother trying to make a shim for it.
+fn format_rusage_data() -> Option<String> {
+    None
+}
+
+#[cfg(unix)]
+/// Tries to build a string with human readable data for several of the rusage
+/// fields. Note that we are focusing mainly on data that we believe to be
+/// supplied on Linux (the `rusage` struct has other fields in it but they are
+/// currently unsupported by Linux).
+fn format_rusage_data() -> Option<String> {
+    let rusage: libc::rusage = unsafe {
+        let mut recv = std::mem::zeroed();
+        // -1 is RUSAGE_CHILDREN, which means to get the rusage for all children
+        // (and grandchildren, etc) processes that have respectively terminated
+        // and been waited for.
+        let retval = libc::getrusage(-1, &mut recv);
+        if retval != 0 {
+            return None;
+        }
+        recv
+    };
+    // Mac OS X reports the maxrss in bytes, not kb.
+    let divisor = if env::consts::OS == "macos" { 1024 } else { 1 };
+    let maxrss = rusage.ru_maxrss + (divisor - 1) / divisor;
+
+    let mut init_str = format!(
+        "user: {USER_SEC}.{USER_USEC:03} \
+         sys: {SYS_SEC}.{SYS_USEC:03} \
+         max rss (kb): {MAXRSS}",
+        USER_SEC = rusage.ru_utime.tv_sec,
+        USER_USEC = rusage.ru_utime.tv_usec,
+        SYS_SEC = rusage.ru_stime.tv_sec,
+        SYS_USEC = rusage.ru_stime.tv_usec,
+        MAXRSS = maxrss
+    );
+
+    // The remaining rusage stats vary in platform support. So we treat
+    // uniformly zero values in each category as "not worth printing", since it
+    // either means no events of that type occurred, or that the platform
+    // does not support it.
+
+    let minflt = rusage.ru_minflt;
+    let majflt = rusage.ru_majflt;
+    if minflt != 0 || majflt != 0 {
+        init_str.push_str(&format!(" page reclaims: {} page faults: {}", minflt, majflt));
+    }
+
+    let inblock = rusage.ru_inblock;
+    let oublock = rusage.ru_oublock;
+    if inblock != 0 || oublock != 0 {
+        init_str.push_str(&format!(" fs block inputs: {} fs block outputs: {}", inblock, oublock));
+    }
+
+    let nvcsw = rusage.ru_nvcsw;
+    let nivcsw = rusage.ru_nivcsw;
+    if nvcsw != 0 || nivcsw != 0 {
+        init_str.push_str(&format!(
+            " voluntary ctxt switches: {} involuntary ctxt switches: {}",
+            nvcsw, nivcsw
+        ));
+    }
+
+    return Some(init_str);
+}

src/bootstrap/builder.rs

@@ -1265,6 +1265,10 @@ impl<'a> Builder<'a> {
             cargo.env("RUSTC_PRINT_STEP_TIMINGS", "1");
         }
 
+        if self.config.print_step_rusage {
+            cargo.env("RUSTC_PRINT_STEP_RUSAGE", "1");
+        }
+
         if self.config.backtrace_on_ice {
             cargo.env("RUSTC_BACKTRACE_ON_ICE", "1");
         }

src/bootstrap/config.rs

@@ -161,6 +161,7 @@ pub struct Config {
     pub verbose_tests: bool,
     pub save_toolstates: Option<PathBuf>,
     pub print_step_timings: bool,
+    pub print_step_rusage: bool,
     pub missing_tools: bool,
 
     // Fallback musl-root for all targets
@@ -380,6 +381,7 @@ struct Build {
     configure_args: Option<Vec<String>>,
     local_rebuild: Option<bool>,
     print_step_timings: Option<bool>,
+    print_step_rusage: Option<bool>,
     check_stage: Option<u32>,
     doc_stage: Option<u32>,
     build_stage: Option<u32>,
@@ -679,6 +681,7 @@ impl Config {
         set(&mut config.configure_args, build.configure_args);
         set(&mut config.local_rebuild, build.local_rebuild);
         set(&mut config.print_step_timings, build.print_step_timings);
+        set(&mut config.print_step_rusage, build.print_step_rusage);
 
         // See https://github.com/rust-lang/compiler-team/issues/326
         config.stage = match config.cmd {