Skip to content

Commit

Permalink
Rollup merge of rust-lang#67777 - Zoxc:time-refactor, r=wesleywiser
Browse files Browse the repository at this point in the history 
Use self profile infrastructure for -Z time and -Z time-passes

There's no longer indentation for -Z time and -Z time-passes and duplicate timers between self profiling and -Z time-passes have been removed.

r? @wesleywiser
  • Loading branch information
@Dylan-DPC
Dylan-DPC authored Jan 2, 2020
2 parents e51b3d8 + 19e37c4 commit 4ba28c8
Show file tree
Hide file tree
Showing 24 changed files with 472 additions and 477 deletions.
4 changes: 1 addition & 3 deletions src/librustc/hir/map/mod.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,9 +11,7 @@ use crate::hir::DefKind;
use crate::hir::*;
use crate::middle::cstore::CrateStoreDyn;
use crate::ty::query::Providers;
use crate::util::common::time;
use crate::util::nodemap::FxHashMap;

use rustc_data_structures::svh::Svh;
use rustc_index::vec::IndexVec;
use rustc_span::hygiene::MacroKind;
Expand Down Expand Up @@ -1244,7 +1242,7 @@ pub fn map_crate<'hir>(
definitions,
};

time(sess, "validate HIR map", || {
sess.time("validate HIR map", || {
hir_id_validator::check_crate(&map);
});

Expand Down
2 changes: 0 additions & 2 deletions src/librustc/lib.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -66,8 +66,6 @@
extern crate bitflags;
#[macro_use]
extern crate scoped_tls;
#[cfg(windows)]
extern crate libc;
#[macro_use]
extern crate rustc_macros;
#[macro_use]
Expand Down
12 changes: 5 additions & 7 deletions src/librustc/lint/context.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,9 +29,7 @@ use crate::middle::privacy::AccessLevels;
use crate::session::Session;
use crate::ty::layout::{LayoutError, LayoutOf, TyLayout};
use crate::ty::{self, print::Printer, subst::GenericArg, Ty, TyCtxt};
use crate::util::common::time;
use crate::util::nodemap::FxHashMap;

use errors::DiagnosticBuilder;
use rustc_data_structures::sync::{self, join, par_iter, ParallelIterator};
use rustc_span::{symbol::Symbol, MultiSpan, Span};
Expand Down Expand Up @@ -1413,7 +1411,7 @@ fn late_lint_crate<'tcx, T: for<'a> LateLintPass<'a, 'tcx>>(tcx: TyCtxt<'tcx>, b
late_lint_pass_crate(tcx, builtin_lints);
} else {
for pass in &mut passes {
time(tcx.sess, &format!("running late lint: {}", pass.name()), || {
tcx.sess.time(&format!("running late lint: {}", pass.name()), || {
late_lint_pass_crate(tcx, LateLintPassObjects { lints: slice::from_mut(pass) });
});
}
Expand All @@ -1422,7 +1420,7 @@ fn late_lint_crate<'tcx, T: for<'a> LateLintPass<'a, 'tcx>>(tcx: TyCtxt<'tcx>, b
tcx.lint_store.late_module_passes.iter().map(|pass| (pass)()).collect();

for pass in &mut passes {
time(tcx.sess, &format!("running late module lint: {}", pass.name()), || {
tcx.sess.time(&format!("running late module lint: {}", pass.name()), || {
late_lint_pass_crate(tcx, LateLintPassObjects { lints: slice::from_mut(pass) });
});
}
Expand All @@ -1436,13 +1434,13 @@ pub fn check_crate<'tcx, T: for<'a> LateLintPass<'a, 'tcx>>(
) {
join(
|| {
time(tcx.sess, "crate lints", || {
tcx.sess.time("crate lints", || {
// Run whole crate non-incremental lints
late_lint_crate(tcx, builtin_lints());
});
},
|| {
time(tcx.sess, "module lints", || {
tcx.sess.time("module lints", || {
// Run per-module lints
par_iter(&tcx.hir().krate().modules).for_each(|(&module, _)| {
tcx.ensure().lint_mod(tcx.hir().local_def_id(module));
Expand Down Expand Up @@ -1540,7 +1538,7 @@ pub fn check_ast_crate<T: EarlyLintPass>(
}
} else {
for pass in &mut passes {
buffered = time(sess, &format!("running lint: {}", pass.name()), || {
buffered = sess.time(&format!("running lint: {}", pass.name()), || {
early_lint_crate(
sess,
lint_store,
Expand Down
30 changes: 14 additions & 16 deletions src/librustc/ty/query/on_disk_cache.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,6 @@ use crate::session::{CrateDisambiguator, Session};
use crate::ty::codec::{self as ty_codec, TyDecoder, TyEncoder};
use crate::ty::context::TyCtxt;
use crate::ty::{self, Ty};
use crate::util::common::{time, time_ext};

use errors::Diagnostic;
use rustc_data_structures::fx::FxHashMap;
Expand Down Expand Up @@ -200,7 +199,7 @@ impl<'sess> OnDiskCache<'sess> {
// Encode query results.
let mut query_result_index = EncodedQueryResultIndex::new();

time(tcx.sess, "encode query results", || {
tcx.sess.time("encode query results", || {
let enc = &mut encoder;
let qri = &mut query_result_index;

Expand Down Expand Up @@ -1056,23 +1055,22 @@ where
E: 'a + TyEncoder,
{
let desc = &format!("encode_query_results for {}", ::std::any::type_name::<Q>());
let _timer = tcx.sess.prof.generic_pass(desc);

time_ext(tcx.sess.time_extended(), desc, || {
let shards = Q::query_cache(tcx).lock_shards();
assert!(shards.iter().all(|shard| shard.active.is_empty()));
for (key, entry) in shards.iter().flat_map(|shard| shard.results.iter()) {
if Q::cache_on_disk(tcx, key.clone(), Some(&entry.value)) {
let dep_node = SerializedDepNodeIndex::new(entry.index.index());
let shards = Q::query_cache(tcx).lock_shards();
assert!(shards.iter().all(|shard| shard.active.is_empty()));
for (key, entry) in shards.iter().flat_map(|shard| shard.results.iter()) {
if Q::cache_on_disk(tcx, key.clone(), Some(&entry.value)) {
let dep_node = SerializedDepNodeIndex::new(entry.index.index());

// Record position of the cache entry.
query_result_index.push((dep_node, AbsoluteBytePos::new(encoder.position())));
// Record position of the cache entry.
query_result_index.push((dep_node, AbsoluteBytePos::new(encoder.position())));

// Encode the type check tables with the `SerializedDepNodeIndex`
// as tag.
encoder.encode_tagged(dep_node, &entry.value)?;
}
// Encode the type check tables with the `SerializedDepNodeIndex`
// as tag.
encoder.encode_tagged(dep_node, &entry.value)?;
}
}

Ok(())
})
Ok(())
}
133 changes: 0 additions & 133 deletions src/librustc/util/common.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,11 +2,9 @@

use rustc_data_structures::sync::Lock;

use std::cell::Cell;
use std::fmt::Debug;
use std::time::{Duration, Instant};

use crate::session::Session;
use syntax::symbol::{sym, Symbol};

#[cfg(test)]
Expand All @@ -17,85 +15,6 @@ pub const FN_OUTPUT_NAME: Symbol = sym::Output;

pub use errors::ErrorReported;

thread_local!(static TIME_DEPTH: Cell<usize> = Cell::new(0));

#[allow(nonstandard_style)]
#[derive(Clone, Debug, PartialEq, Eq)]
pub struct QueryMsg {
pub query: &'static str,
pub msg: Option<String>,
}

/// Read the current depth of `time()` calls. This is used to
/// encourage indentation across threads.
pub fn time_depth() -> usize {
TIME_DEPTH.with(|slot| slot.get())
}

/// Sets the current depth of `time()` calls. The idea is to call
/// `set_time_depth()` with the result from `time_depth()` in the
/// parent thread.
pub fn set_time_depth(depth: usize) {
TIME_DEPTH.with(|slot| slot.set(depth));
}

pub fn time<T, F>(sess: &Session, what: &str, f: F) -> T
where
F: FnOnce() -> T,
{
time_ext(sess.time_passes(), what, f)
}

pub fn time_ext<T, F>(do_it: bool, what: &str, f: F) -> T
where
F: FnOnce() -> T,
{
if !do_it {
return f();
}

let old = TIME_DEPTH.with(|slot| {
let r = slot.get();
slot.set(r + 1);
r
});

let start = Instant::now();
let rv = f();
let dur = start.elapsed();

print_time_passes_entry(true, what, dur);

TIME_DEPTH.with(|slot| slot.set(old));

rv
}

pub fn print_time_passes_entry(do_it: bool, what: &str, dur: Duration) {
if !do_it {
return;
}

let indentation = TIME_DEPTH.with(|slot| slot.get());

let mem_string = match get_resident() {
Some(n) => {
let mb = n as f64 / 1_000_000.0;
format!("; rss: {}MB", mb.round() as usize)
}
None => String::new(),
};
println!(
"{}time: {}{}\t{}",
" ".repeat(indentation),
duration_to_secs_str(dur),
mem_string,
what
);
}

pub use rustc_session::utils::duration_to_secs_str;

pub fn to_readable_str(mut val: usize) -> String {
let mut groups = vec![];
loop {
Expand Down Expand Up @@ -128,58 +47,6 @@ where
rv
}

// Memory reporting
#[cfg(unix)]
fn get_resident() -> Option<usize> {
use std::fs;

let field = 1;
let contents = fs::read("/proc/self/statm").ok()?;
let contents = String::from_utf8(contents).ok()?;
let s = contents.split_whitespace().nth(field)?;
let npages = s.parse::<usize>().ok()?;
Some(npages * 4096)
}

#[cfg(windows)]
fn get_resident() -> Option<usize> {
type BOOL = i32;
type DWORD = u32;
type HANDLE = *mut u8;
use libc::size_t;
use std::mem;
#[repr(C)]
#[allow(non_snake_case)]
struct PROCESS_MEMORY_COUNTERS {
cb: DWORD,
PageFaultCount: DWORD,
PeakWorkingSetSize: size_t,
WorkingSetSize: size_t,
QuotaPeakPagedPoolUsage: size_t,
QuotaPagedPoolUsage: size_t,
QuotaPeakNonPagedPoolUsage: size_t,
QuotaNonPagedPoolUsage: size_t,
PagefileUsage: size_t,
PeakPagefileUsage: size_t,
}
type PPROCESS_MEMORY_COUNTERS = *mut PROCESS_MEMORY_COUNTERS;
#[link(name = "psapi")]
extern "system" {
fn GetCurrentProcess() -> HANDLE;
fn GetProcessMemoryInfo(
Process: HANDLE,
ppsmemCounters: PPROCESS_MEMORY_COUNTERS,
cb: DWORD,
) -> BOOL;
}
let mut pmc: PROCESS_MEMORY_COUNTERS = unsafe { mem::zeroed() };
pmc.cb = mem::size_of_val(&pmc) as DWORD;
match unsafe { GetProcessMemoryInfo(GetCurrentProcess(), &mut pmc, pmc.cb) } {
0 => None,
_ => Some(pmc.WorkingSetSize as usize),
}
}

pub fn indent<R, F>(op: F) -> R
where
R: Debug,
Expand Down
12 changes: 5 additions & 7 deletions src/librustc_codegen_llvm/back/lto.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,6 @@ use rustc::dep_graph::WorkProduct;
use rustc::hir::def_id::LOCAL_CRATE;
use rustc::middle::exported_symbols::SymbolExportLevel;
use rustc::session::config::{self, Lto};
use rustc::util::common::time_ext;
use rustc_codegen_ssa::back::lto::{LtoModuleCodegen, SerializedModule, ThinModule, ThinShared};
use rustc_codegen_ssa::back::symbol_export;
use rustc_codegen_ssa::back::write::{CodegenContext, FatLTOInput, ModuleConfig};
Expand Down Expand Up @@ -121,7 +120,7 @@ fn prepare_lto(
info!("adding bytecode {}", name);
let bc_encoded = data.data();

let (bc, id) = time_ext(cgcx.time_passes, &format!("decode {}", name), || {
let (bc, id) = cgcx.prof.generic_pass(&format!("decode {}", name)).run(|| {
match DecodedBytecode::new(bc_encoded) {
Ok(b) => Ok((b.bytecode(), b.identifier().to_string())),
Err(e) => Err(diag_handler.fatal(&e)),
Expand Down Expand Up @@ -281,9 +280,8 @@ fn fat_lto(
// save and persist everything with the original module.
let mut linker = Linker::new(llmod);
for (bc_decoded, name) in serialized_modules {
let _timer = cgcx.prof.generic_activity("LLVM_fat_lto_link_module");
info!("linking {:?}", name);
time_ext(cgcx.time_passes, &format!("ll link {:?}", name), || {
cgcx.prof.generic_pass(&format!("ll link {:?}", name)).run(|| {
let data = bc_decoded.data();
linker.add(&data).map_err(|()| {
let msg = format!("failed to load bc of {:?}", name);
Expand Down Expand Up @@ -634,9 +632,9 @@ pub(crate) fn run_pass_manager(
llvm::LLVMRustAddPass(pm, pass.unwrap());
}

time_ext(cgcx.time_passes, "LTO passes", || {
llvm::LLVMRunPassManager(pm, module.module_llvm.llmod())
});
cgcx.prof
.generic_pass("LTO passes")
.run(|| llvm::LLVMRunPassManager(pm, module.module_llvm.llmod()));

llvm::LLVMDisposePassManager(pm);
}
Expand Down
Loading

0 comments on commit 4ba28c8

Please sign in to comment.