rustc: improve -Z trans-stats to report per-fn LLVM instruction counts and translation timing
This commit is contained in:
parent
0c6fc46c03
commit
f80d6dc4c1
5 changed files with 66 additions and 28 deletions
|
@ -72,6 +72,7 @@ use std::uint;
|
|||
use std::vec;
|
||||
use std::local_data;
|
||||
use extra::time;
|
||||
use extra::sort;
|
||||
use syntax::ast::ident;
|
||||
use syntax::ast_map::{path, path_elt_to_str, path_name};
|
||||
use syntax::ast_util::{local_def, path_to_ident};
|
||||
|
@ -141,6 +142,48 @@ fn fcx_has_nonzero_span(fcx: fn_ctxt) -> bool {
|
|||
}
|
||||
}
|
||||
|
||||
struct StatRecorder<'self> {
|
||||
ccx: @mut CrateContext,
|
||||
name: &'self str,
|
||||
start: u64,
|
||||
istart: uint,
|
||||
}
|
||||
|
||||
impl<'self> StatRecorder<'self> {
|
||||
pub fn new(ccx: @mut CrateContext,
|
||||
name: &'self str) -> StatRecorder<'self> {
|
||||
let start = if ccx.sess.trans_stats() {
|
||||
time::precise_time_ns()
|
||||
} else {
|
||||
0
|
||||
};
|
||||
let istart = ccx.stats.n_llvm_insns;
|
||||
StatRecorder {
|
||||
ccx: ccx,
|
||||
name: name,
|
||||
start: start,
|
||||
istart: istart,
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
#[unsafe_destructor]
|
||||
impl<'self> Drop for StatRecorder<'self> {
|
||||
pub fn drop(&self) {
|
||||
if self.ccx.sess.trans_stats() {
|
||||
let end = time::precise_time_ns();
|
||||
let elapsed = ((end - self.start) / 1_000_000) as uint;
|
||||
let iend = self.ccx.stats.n_llvm_insns;
|
||||
self.ccx.stats.fn_stats.push((self.name.to_owned(),
|
||||
elapsed,
|
||||
iend - self.istart));
|
||||
self.ccx.stats.n_fns += 1;
|
||||
// Reset LLVM insn count to avoid compound costs.
|
||||
self.ccx.stats.n_llvm_insns = self.istart;
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
pub fn decl_fn(llmod: ModuleRef, name: &str, cc: lib::llvm::CallConv, ty: Type) -> ValueRef {
|
||||
let llfn: ValueRef = do name.as_c_str |buf| {
|
||||
unsafe {
|
||||
|
@ -1866,18 +1909,16 @@ pub fn trans_fn(ccx: @mut CrateContext,
|
|||
param_substs: Option<@param_substs>,
|
||||
id: ast::node_id,
|
||||
attrs: &[ast::attribute]) {
|
||||
let do_time = ccx.sess.trans_stats();
|
||||
let start = if do_time { time::get_time() }
|
||||
else { time::Timespec::new(0, 0) };
|
||||
|
||||
let the_path_str = path_str(ccx.sess, path);
|
||||
let _s = StatRecorder::new(ccx, the_path_str);
|
||||
debug!("trans_fn(self_arg=%?, param_substs=%s)",
|
||||
self_arg,
|
||||
param_substs.repr(ccx.tcx));
|
||||
let _icx = push_ctxt("trans_fn");
|
||||
ccx.stats.n_fns += 1;
|
||||
let the_path_str = path_str(ccx.sess, path);
|
||||
let output_type = ty::ty_fn_ret(ty::node_id_to_type(ccx.tcx, id));
|
||||
trans_closure(ccx,
|
||||
path,
|
||||
copy path,
|
||||
decl,
|
||||
body,
|
||||
llfndecl,
|
||||
|
@ -1893,10 +1934,6 @@ pub fn trans_fn(ccx: @mut CrateContext,
|
|||
}
|
||||
},
|
||||
|_bcx| { });
|
||||
if do_time {
|
||||
let end = time::get_time();
|
||||
ccx.log_fn_time(the_path_str, start, end);
|
||||
}
|
||||
}
|
||||
|
||||
pub fn trans_enum_variant(ccx: @mut CrateContext,
|
||||
|
@ -2961,8 +2998,14 @@ pub fn trans_crate(sess: session::Session,
|
|||
io::println(fmt!("n_monos: %u", ccx.stats.n_monos));
|
||||
io::println(fmt!("n_inlines: %u", ccx.stats.n_inlines));
|
||||
io::println(fmt!("n_closures: %u", ccx.stats.n_closures));
|
||||
io::println("fn stats:");
|
||||
do sort::quick_sort(ccx.stats.fn_stats) |&(_, _, insns_a), &(_, _, insns_b)| {
|
||||
insns_a > insns_b
|
||||
}
|
||||
for ccx.stats.fn_stats.iter().advance |&(name, ms, insns)| {
|
||||
io::println(fmt!("%u insns, %u ms, %s", insns, ms, name));
|
||||
}
|
||||
}
|
||||
|
||||
if ccx.sess.count_llvm_insns() {
|
||||
for ccx.stats.llvm_insns.iter().advance |(&k, &v)| {
|
||||
io::println(fmt!("%-7u %s", v, k));
|
||||
|
|
|
@ -46,6 +46,9 @@ pub fn B(cx: block) -> BuilderRef {
|
|||
}
|
||||
|
||||
pub fn count_insn(cx: block, category: &str) {
|
||||
if cx.ccx().sess.trans_stats() {
|
||||
cx.ccx().stats.n_llvm_insns += 1;
|
||||
}
|
||||
do base::with_insn_ctxt |v| {
|
||||
let h = &mut cx.ccx().stats.llvm_insns;
|
||||
|
||||
|
|
|
@ -96,8 +96,10 @@ pub struct Stats {
|
|||
n_monos: uint,
|
||||
n_inlines: uint,
|
||||
n_closures: uint,
|
||||
n_llvm_insns: uint,
|
||||
llvm_insn_ctxt: ~[~str],
|
||||
llvm_insns: HashMap<~str, uint>,
|
||||
fn_times: ~[(~str, int)] // (ident, time)
|
||||
fn_stats: ~[(~str, uint, uint)] // (ident, time-in-ms, llvm-instructions)
|
||||
}
|
||||
|
||||
pub struct BuilderRef_res {
|
||||
|
|
|
@ -210,8 +210,10 @@ impl CrateContext {
|
|||
n_monos: 0u,
|
||||
n_inlines: 0u,
|
||||
n_closures: 0u,
|
||||
n_llvm_insns: 0u,
|
||||
llvm_insn_ctxt: ~[],
|
||||
llvm_insns: HashMap::new(),
|
||||
fn_times: ~[]
|
||||
fn_stats: ~[]
|
||||
},
|
||||
upcalls: upcall::declare_upcalls(targ_cfg, llmod),
|
||||
tydesc_type: tydesc_type,
|
||||
|
@ -226,12 +228,6 @@ impl CrateContext {
|
|||
}
|
||||
}
|
||||
}
|
||||
|
||||
pub fn log_fn_time(&mut self, name: ~str, start: time::Timespec, end: time::Timespec) {
|
||||
let elapsed = 1000 * ((end.sec - start.sec) as int) +
|
||||
((end.nsec as int) - (start.nsec as int)) / 1000000;
|
||||
self.stats.fn_times.push((name, elapsed));
|
||||
}
|
||||
}
|
||||
|
||||
#[unsafe_destructor]
|
||||
|
|
|
@ -738,15 +738,9 @@ pub fn make_generic_glue(ccx: @mut CrateContext,
|
|||
name: &str)
|
||||
-> ValueRef {
|
||||
let _icx = push_ctxt("make_generic_glue");
|
||||
if !ccx.sess.trans_stats() {
|
||||
return make_generic_glue_inner(ccx, t, llfn, helper);
|
||||
}
|
||||
|
||||
let start = time::get_time();
|
||||
let llval = make_generic_glue_inner(ccx, t, llfn, helper);
|
||||
let end = time::get_time();
|
||||
ccx.log_fn_time(fmt!("glue %s %s", name, ty_to_short_str(ccx.tcx, t)), start, end);
|
||||
return llval;
|
||||
let glue_name = fmt!("glue %s %s", name, ty_to_short_str(ccx.tcx, t));
|
||||
let _s = StatRecorder::new(ccx, glue_name);
|
||||
make_generic_glue_inner(ccx, t, llfn, helper)
|
||||
}
|
||||
|
||||
pub fn emit_tydescs(ccx: &mut CrateContext) {
|
||||
|
|
Loading…
Reference in a new issue