From 0d8bf72a36eb78c1a9bf721b9af3055f62cfc3dc Mon Sep 17 00:00:00 2001 From: "Felix S. Klock II" Date: Fri, 19 Feb 2021 13:25:26 -0500 Subject: [PATCH 1/2] Created experimental build.print_step_rusage setting Intended to piggy-back on output from existing build.print_step_timings setting. --- config.toml.example | 6 ++++++ src/bootstrap/builder.rs | 4 ++++ src/bootstrap/config.rs | 3 +++ 3 files changed, 13 insertions(+) diff --git a/config.toml.example b/config.toml.example index f3bc98d78aed4..ba382aac828d4 100644 --- a/config.toml.example +++ b/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 # ============================================================================= diff --git a/src/bootstrap/builder.rs b/src/bootstrap/builder.rs index 61554a316d0a1..c0175a0710fdc 100644 --- a/src/bootstrap/builder.rs +++ b/src/bootstrap/builder.rs @@ -1259,6 +1259,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"); } diff --git a/src/bootstrap/config.rs b/src/bootstrap/config.rs index d50d605d5c695..b2af8e59b7c9f 100644 --- a/src/bootstrap/config.rs +++ b/src/bootstrap/config.rs @@ -161,6 +161,7 @@ pub struct Config { pub verbose_tests: bool, pub save_toolstates: Option, 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>, local_rebuild: Option, print_step_timings: Option, + print_step_rusage: Option, check_stage: Option, doc_stage: Option, build_stage: Option, @@ -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 { From f2d70c5d188472f5655c9cc8ba47e52d89d8fdd7 Mon Sep 17 00:00:00 2001 From: "Felix S. Klock II" Date: Fri, 19 Feb 2021 13:27:39 -0500 Subject: [PATCH 2/2] Implementation of build.print_step_rusage. On non-unix platforms, does not try to call `getrusage` (and does not attempt to implement its own shim; that could be follow-on work, though its probably best to not invest too much effort there, versus using separate dedicated tooling). On unix platforms, calls libc::rusage and attempts to emit the subset of fields that are supported on Linux and Mac OS X. Omits groups of related stats which appear to be unsupported on the platform (due to them all remaining zero). Adjusts output to compensate for Mac using bytes instead of kb (a well known discrepancy on Mac OS X). However, so far I observe a lot of strange values (orders of magnitude wrong) reported on Mac OS X in some cases, so I would not trust this in that context currently. --- src/bootstrap/bin/rustc.rs | 82 ++++++++++++++++++++++++++++++++++++-- 1 file changed, 79 insertions(+), 3 deletions(-) diff --git a/src/bootstrap/bin/rustc.rs b/src/bootstrap/bin/rustc.rs index 3694bdbf67054..670046ff08b56 100644 --- a/src/bootstrap/bin/rustc.rs +++ b/src/bootstrap/bin/rustc.rs @@ -155,16 +155,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()), ); } } @@ -192,3 +200,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 { + 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 { + 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); +}