From 90419d36bd05718bce2b1a6eafaac8469a327bec Mon Sep 17 00:00:00 2001 From: Nicholas Nethercote Date: Tue, 25 Jun 2019 10:04:47 +1000 Subject: [PATCH 1/2] Remove `solve_nll_region_constraints` measurements from `-Ztime-passes` output. Because it pollutes the output with hundreds or thousands of uninteresting lines for which the time duration is always(?) 0.000s. --- .../borrow_check/nll/region_infer/mod.rs | 18 +----------------- 1 file changed, 1 insertion(+), 17 deletions(-) diff --git a/src/librustc_mir/borrow_check/nll/region_infer/mod.rs b/src/librustc_mir/borrow_check/nll/region_infer/mod.rs index 4e609460c1f70..40388722bcac9 100644 --- a/src/librustc_mir/borrow_check/nll/region_infer/mod.rs +++ b/src/librustc_mir/borrow_check/nll/region_infer/mod.rs @@ -20,7 +20,7 @@ use rustc::mir::{ ConstraintCategory, Local, Location, }; use rustc::ty::{self, subst::SubstsRef, RegionVid, Ty, TyCtxt, TypeFoldable}; -use rustc::util::common::{self, ErrorReported}; +use rustc::util::common::ErrorReported; use rustc_data_structures::binary_search_util; use rustc_data_structures::bit_set::BitSet; use rustc_data_structures::fx::{FxHashMap, FxHashSet}; @@ -468,22 +468,6 @@ impl<'tcx> RegionInferenceContext<'tcx> { upvars: &[Upvar], mir_def_id: DefId, errors_buffer: &mut Vec, - ) -> Option> { - common::time_ext( - infcx.tcx.sess.time_extended(), - Some(infcx.tcx.sess), - &format!("solve_nll_region_constraints({:?})", mir_def_id), - || self.solve_inner(infcx, body, upvars, mir_def_id, errors_buffer), - ) - } - - fn solve_inner( - &mut self, - infcx: &InferCtxt<'_, 'tcx>, - body: &Body<'tcx>, - upvars: &[Upvar], - mir_def_id: DefId, - errors_buffer: &mut Vec, ) -> Option> { self.propagate_constraints(body); From 87b103d4a99193bf57a17866fb99596df7d31d8b Mon Sep 17 00:00:00 2001 From: Nicholas Nethercote Date: Tue, 25 Jun 2019 13:52:07 +1000 Subject: [PATCH 2/2] Add a "total" measurement to -Ztime-passes. This is useful for getting the total compilation time at the end. To do this, the patch changes `print_time_passes_entry` to not increment the depth, which means that `print_time_passes_entry_internal` is no longer needed. --- src/librustc/util/common.rs | 14 +---------- src/librustc_codegen_ssa/back/write.rs | 2 +- src/librustc_codegen_ssa/base.rs | 5 +++- src/librustc_driver/lib.rs | 32 +++++++++++++++++++++----- 4 files changed, 32 insertions(+), 21 deletions(-) diff --git a/src/librustc/util/common.rs b/src/librustc/util/common.rs index 2140018223c34..8e7936dae0976 100644 --- a/src/librustc/util/common.rs +++ b/src/librustc/util/common.rs @@ -170,7 +170,7 @@ pub fn time_ext(do_it: bool, sess: Option<&Session>, what: &str, f: F) -> } } - print_time_passes_entry_internal(what, dur); + print_time_passes_entry(true, what, dur); TIME_DEPTH.with(|slot| slot.set(old)); @@ -182,18 +182,6 @@ pub fn print_time_passes_entry(do_it: bool, what: &str, dur: Duration) { return } - let old = TIME_DEPTH.with(|slot| { - let r = slot.get(); - slot.set(r + 1); - r - }); - - print_time_passes_entry_internal(what, dur); - - TIME_DEPTH.with(|slot| slot.set(old)); -} - -fn print_time_passes_entry_internal(what: &str, dur: Duration) { let indentation = TIME_DEPTH.with(|slot| slot.get()); let mem_string = match get_resident() { diff --git a/src/librustc_codegen_ssa/back/write.rs b/src/librustc_codegen_ssa/back/write.rs index fbf57701c5a95..7bb2cc7c08977 100644 --- a/src/librustc_codegen_ssa/back/write.rs +++ b/src/librustc_codegen_ssa/back/write.rs @@ -1554,7 +1554,7 @@ fn start_executing_work( let total_llvm_time = Instant::now().duration_since(llvm_start_time); // This is the top-level timing for all of LLVM, set the time-depth // to zero. - set_time_depth(0); + set_time_depth(1); print_time_passes_entry(cgcx.time_passes, "LLVM passes", total_llvm_time); diff --git a/src/librustc_codegen_ssa/base.rs b/src/librustc_codegen_ssa/base.rs index d06460fc85696..a554bf7761c93 100644 --- a/src/librustc_codegen_ssa/base.rs +++ b/src/librustc_codegen_ssa/base.rs @@ -25,7 +25,7 @@ use rustc::ty::{self, Ty, TyCtxt, Instance}; use rustc::ty::layout::{self, Align, TyLayout, LayoutOf, VariantIdx, HasTyCtxt}; use rustc::ty::query::Providers; use rustc::middle::cstore::{self, LinkagePreference}; -use rustc::util::common::{time, print_time_passes_entry}; +use rustc::util::common::{time, print_time_passes_entry, set_time_depth, time_depth}; use rustc::session::config::{self, EntryFnType, Lto}; use rustc::session::Session; use rustc::util::nodemap::FxHashMap; @@ -639,9 +639,12 @@ pub fn codegen_crate( // Since the main thread is sometimes blocked during codegen, we keep track // -Ztime-passes output manually. + let time_depth = time_depth(); + set_time_depth(time_depth + 1); print_time_passes_entry(tcx.sess.time_passes(), "codegen to LLVM IR", total_codegen_time); + set_time_depth(time_depth); ::rustc_incremental::assert_module_sources::assert_module_sources(tcx); diff --git a/src/librustc_driver/lib.rs b/src/librustc_driver/lib.rs index 5fb6ed31b0693..3258e2517319b 100644 --- a/src/librustc_driver/lib.rs +++ b/src/librustc_driver/lib.rs @@ -38,7 +38,8 @@ use rustc::session::{early_error, early_warn}; use rustc::lint::Lint; use rustc::lint; use rustc::hir::def_id::LOCAL_CRATE; -use rustc::util::common::{time, ErrorReported, install_panic_hook}; +use rustc::util::common::{ErrorReported, install_panic_hook, print_time_passes_entry}; +use rustc::util::common::{set_time_depth, time}; use rustc_metadata::locator; use rustc_metadata::cstore::CStore; use rustc_codegen_utils::codegen_backend::CodegenBackend; @@ -54,11 +55,12 @@ use std::default::Default; use std::env; use std::ffi::OsString; use std::io::{self, Read, Write}; +use std::mem; use std::panic::{self, catch_unwind}; use std::path::PathBuf; use std::process::{self, Command, Stdio}; use std::str; -use std::mem; +use std::time::Instant; use syntax::ast; use syntax::source_map::FileLoader; @@ -72,7 +74,7 @@ pub mod pretty; /// Exit status code used for successful compilation and help output. pub const EXIT_SUCCESS: i32 = 0; -/// Exit status code used for compilation failures and invalid flags. +/// Exit status code used for compilation failures and invalid flags. pub const EXIT_FAILURE: i32 = 1; const BUG_REPORT_URL: &str = "https://github.com/rust-lang/rust/blob/master/CONTRIBUTING.\ @@ -118,6 +120,18 @@ pub struct DefaultCallbacks; impl Callbacks for DefaultCallbacks {} +#[derive(Default)] +pub struct TimePassesCallbacks { + time_passes: bool, +} + +impl Callbacks for TimePassesCallbacks { + fn config(&mut self, config: &mut interface::Config) { + self.time_passes = + config.opts.debugging_opts.time_passes || config.opts.debugging_opts.time; + } +} + // Parse args and run the compiler. This is the primary entry point for rustc. // See comments on CompilerCalls below for details about the callbacks argument. // The FileLoader provides a way to load files from sources other than the file system. @@ -1169,7 +1183,9 @@ pub fn init_rustc_env_logger() { } pub fn main() { + let start = Instant::now(); init_rustc_env_logger(); + let mut callbacks = TimePassesCallbacks::default(); let result = report_ices_to_stderr_if_any(|| { let args = env::args_os().enumerate() .map(|(i, arg)| arg.into_string().unwrap_or_else(|arg| { @@ -1177,10 +1193,14 @@ pub fn main() { &format!("Argument {} is not valid Unicode: {:?}", i, arg)) })) .collect::>(); - run_compiler(&args, &mut DefaultCallbacks, None, None) + run_compiler(&args, &mut callbacks, None, None) }).and_then(|result| result); - process::exit(match result { + let exit_code = match result { Ok(_) => EXIT_SUCCESS, Err(_) => EXIT_FAILURE, - }); + }; + // The extra `\t` is necessary to align this label with the others. + set_time_depth(0); + print_time_passes_entry(callbacks.time_passes, "\ttotal", start.elapsed()); + process::exit(exit_code); }