diff --git a/src/librustc/session/config.rs b/src/librustc/session/config.rs index 562dce6a1b12..79e14212db42 100644 --- a/src/librustc/session/config.rs +++ b/src/librustc/session/config.rs @@ -908,6 +908,8 @@ options! {DebuggingOptions, DebuggingSetter, basic_debugging_options, "dump MIR state at various points in translation"), dump_mir_dir: Option = (None, parse_opt_string, [UNTRACKED], "the directory the MIR is dumped into"), + perf_stats: bool = (false, parse_bool, [UNTRACKED], + "print some performance-related statistics"), } pub fn default_lib_output() -> CrateType { diff --git a/src/librustc/session/mod.rs b/src/librustc/session/mod.rs index 338c65637995..cc115cbeb85b 100644 --- a/src/librustc/session/mod.rs +++ b/src/librustc/session/mod.rs @@ -18,6 +18,7 @@ use session::search_paths::PathKind; use session::config::{DebugInfoLevel, PanicStrategy}; use ty::tls; use util::nodemap::{NodeMap, FnvHashMap}; +use util::common::duration_to_secs_str; use mir::transform as mir_pass; use syntax::ast::{NodeId, Name}; @@ -43,6 +44,7 @@ use std::env; use std::ffi::CString; use std::rc::Rc; use std::fmt; +use std::time::Duration; use libc::c_int; pub mod config; @@ -104,9 +106,23 @@ pub struct Session { incr_comp_session: RefCell, + /// Some measurements that are being gathered during compilation. + pub perf_stats: PerfStats, + next_node_id: Cell, } +pub struct PerfStats { + // The accumulated time needed for computing the SVH of the crate + pub svh_time: Cell, + // The accumulated time spent on computing incr. comp. hashes + pub incr_comp_hashes_time: Cell, + // The number of incr. comp. hash computations performed + pub incr_comp_hashes_count: Cell, + // The accumulated time spent on computing symbol hashes + pub symbol_hash_time: Cell, +} + impl Session { pub fn local_crate_disambiguator(&self) -> token::InternedString { self.crate_disambiguator.borrow().clone() @@ -404,6 +420,17 @@ impl Session { None } } + + pub fn print_perf_stats(&self) { + println!("Total time spent computing SVHs: {}", + duration_to_secs_str(self.perf_stats.svh_time.get())); + println!("Total time spent computing incr. comp. hashes: {}", + duration_to_secs_str(self.perf_stats.incr_comp_hashes_time.get())); + println!("Total number of incr. comp. hashes computed: {}", + self.perf_stats.incr_comp_hashes_count.get()); + println!("Total time spent computing symbol hashes: {}", + duration_to_secs_str(self.perf_stats.symbol_hash_time.get())); + } } pub fn build_session(sopts: config::Options, @@ -520,6 +547,12 @@ pub fn build_session_(sopts: config::Options, available_macros: RefCell::new(HashSet::new()), imported_macro_spans: RefCell::new(HashMap::new()), incr_comp_session: RefCell::new(IncrCompSession::NotInitialized), + perf_stats: PerfStats { + svh_time: Cell::new(Duration::from_secs(0)), + incr_comp_hashes_time: Cell::new(Duration::from_secs(0)), + incr_comp_hashes_count: Cell::new(0), + symbol_hash_time: Cell::new(Duration::from_secs(0)), + } }; init_llvm(&sess); diff --git a/src/librustc/util/common.rs b/src/librustc/util/common.rs index bdfb97549d5d..78f20b77f318 100644 --- a/src/librustc/util/common.rs +++ b/src/librustc/util/common.rs @@ -17,7 +17,7 @@ use std::fmt::Debug; use std::hash::{Hash, BuildHasher}; use std::iter::repeat; use std::path::Path; -use std::time::Instant; +use std::time::{Duration, Instant}; use hir; use hir::intravisit; @@ -47,12 +47,6 @@ pub fn time(do_it: bool, what: &str, f: F) -> T where let rv = f(); let dur = start.elapsed(); - // Hack up our own formatting for the duration to make it easier for scripts - // to parse (always use the same number of decimal places and the same unit). - const NANOS_PER_SEC: f64 = 1_000_000_000.0; - let secs = dur.as_secs() as f64; - let secs = secs + dur.subsec_nanos() as f64 / NANOS_PER_SEC; - let mem_string = match get_resident() { Some(n) => { let mb = n as f64 / 1_000_000.0; @@ -60,14 +54,37 @@ pub fn time(do_it: bool, what: &str, f: F) -> T where } None => "".to_owned(), }; - println!("{}time: {:.3}{}\t{}", repeat(" ").take(old).collect::(), - secs, mem_string, what); + println!("{}time: {}{}\t{}", + repeat(" ").take(old).collect::(), + duration_to_secs_str(dur), + mem_string, + what); DEPTH.with(|slot| slot.set(old)); rv } +// Hack up our own formatting for the duration to make it easier for scripts +// to parse (always use the same number of decimal places and the same unit). +pub fn duration_to_secs_str(dur: Duration) -> String { + const NANOS_PER_SEC: f64 = 1_000_000_000.0; + let secs = dur.as_secs() as f64 + + dur.subsec_nanos() as f64 / NANOS_PER_SEC; + + format!("{:.3}", secs) +} + +pub fn record_time(accu: &Cell, f: F) -> T where + F: FnOnce() -> T, +{ + let start = Instant::now(); + let rv = f(); + let duration = start.elapsed(); + accu.set(duration + accu.get()); + rv +} + // Like std::macros::try!, but for Option<>. macro_rules! option_try( ($e:expr) => (match $e { Some(e) => e, None => return None }) diff --git a/src/librustc_driver/driver.rs b/src/librustc_driver/driver.rs index 94092be4922b..e8137430a064 100644 --- a/src/librustc_driver/driver.rs +++ b/src/librustc_driver/driver.rs @@ -233,6 +233,10 @@ pub fn compile_input(sess: &Session, // any more, we can finalize it (which involves renaming it) rustc_incremental::finalize_session_directory(sess, trans.link.crate_hash); + if sess.opts.debugging_opts.perf_stats { + sess.print_perf_stats(); + } + controller_entry_point!(compilation_done, sess, CompileState::state_when_compilation_done(input, sess, outdir, output), diff --git a/src/librustc_trans/back/symbol_names.rs b/src/librustc_trans/back/symbol_names.rs index 9b02cbe6721f..00f29b7412ed 100644 --- a/src/librustc_trans/back/symbol_names.rs +++ b/src/librustc_trans/back/symbol_names.rs @@ -108,6 +108,7 @@ use rustc::ty::{Ty, TyCtxt, TypeFoldable}; use rustc::ty::item_path::{self, ItemPathBuffer, RootMode}; use rustc::ty::subst::Substs; use rustc::hir::map::definitions::{DefPath, DefPathData}; +use rustc::util::common::record_time; use syntax::attr; use syntax::parse::token::{self, InternedString}; @@ -138,33 +139,35 @@ fn get_symbol_hash<'a, 'tcx>(scx: &SharedCrateContext<'a, 'tcx>, let tcx = scx.tcx(); - let mut hash_state = scx.symbol_hasher().borrow_mut(); + return record_time(&tcx.sess.perf_stats.symbol_hash_time, || { + let mut hash_state = scx.symbol_hasher().borrow_mut(); - hash_state.reset(); + hash_state.reset(); - // the main symbol name is not necessarily unique; hash in the - // compiler's internal def-path, guaranteeing each symbol has a - // truly unique path - hash_state.input_str(&def_path.to_string(tcx)); + // the main symbol name is not necessarily unique; hash in the + // compiler's internal def-path, guaranteeing each symbol has a + // truly unique path + hash_state.input_str(&def_path.to_string(tcx)); - // Include the main item-type. Note that, in this case, the - // assertions about `needs_subst` may not hold, but this item-type - // ought to be the same for every reference anyway. - assert!(!item_type.has_erasable_regions()); - let encoded_item_type = tcx.sess.cstore.encode_type(tcx, item_type, def_id_to_string); - hash_state.input(&encoded_item_type[..]); + // Include the main item-type. Note that, in this case, the + // assertions about `needs_subst` may not hold, but this item-type + // ought to be the same for every reference anyway. + assert!(!item_type.has_erasable_regions()); + let encoded_item_type = tcx.sess.cstore.encode_type(tcx, item_type, def_id_to_string); + hash_state.input(&encoded_item_type[..]); - // also include any type parameters (for generic items) - if let Some(substs) = substs { - for t in substs.types() { - assert!(!t.has_erasable_regions()); - assert!(!t.needs_subst()); - let encoded_type = tcx.sess.cstore.encode_type(tcx, t, def_id_to_string); - hash_state.input(&encoded_type[..]); + // also include any type parameters (for generic items) + if let Some(substs) = substs { + for t in substs.types() { + assert!(!t.has_erasable_regions()); + assert!(!t.needs_subst()); + let encoded_type = tcx.sess.cstore.encode_type(tcx, t, def_id_to_string); + hash_state.input(&encoded_type[..]); + } } - } - return format!("h{}", truncated_hash_result(&mut *hash_state)); + format!("h{}", truncated_hash_result(&mut *hash_state)) + }); fn truncated_hash_result(symbol_hasher: &mut Sha256) -> String { let output = symbol_hasher.result_bytes();