"enable queries of the dependency graph for regression testing"),
profile_queries: bool = (false, parse_bool, [UNTRACKED],
"trace and profile the queries of the incremental compilation framework"),
+ profile_queries_and_keys: bool = (false, parse_bool, [UNTRACKED],
+ "trace and profile the queries and keys of the incremental compilation framework"),
no_analysis: bool = (false, parse_bool, [UNTRACKED],
"parse and expand the source, but run no analysis"),
extra_plugins: Vec<String> = (Vec::new(), parse_list, [TRACKED],
}
pub fn verbose(&self) -> bool { self.opts.debugging_opts.verbose }
pub fn time_passes(&self) -> bool { self.opts.debugging_opts.time_passes }
- pub fn profile_queries(&self) -> bool { self.opts.debugging_opts.profile_queries }
+ pub fn profile_queries(&self) -> bool {
+ self.opts.debugging_opts.profile_queries ||
+ self.opts.debugging_opts.profile_queries_and_keys
+ }
+ pub fn profile_queries_and_keys(&self) -> bool {
+ self.opts.debugging_opts.profile_queries_and_keys
+ }
pub fn count_llvm_insns(&self) -> bool {
self.opts.debugging_opts.count_llvm_insns
}
impl<'tcx> QueryDescription for queries::lint_levels<'tcx> {
fn describe(_tcx: TyCtxt, _: CrateNum) -> String {
format!("computing the lint levels for items in this crate")
+ }
}
// If enabled, send a message to the profile-queries thread
macro_rules! profq_msg {
($tcx:expr, $msg:expr) => {
if cfg!(debug_assertions) {
- if $tcx.sess.opts.debugging_opts.profile_queries {
+ if $tcx.sess.profile_queries() {
profq_msg($msg)
}
}
}
}
+// If enabled, format a key using its debug string, which can be
+// expensive to compute (in terms of time).
+macro_rules! profq_key {
+ ($tcx:expr, $key:expr) => {
+ if cfg!(debug_assertions) {
+ if $tcx.sess.profile_queries_and_keys() {
+ Some(format!("{:?}", $key))
+ } else { None }
+ } else { None }
+ }
+}
+
macro_rules! define_maps {
(<$tcx:tt>
$($(#[$attr:meta])*
#[allow(bad_style)]
#[derive(Clone, Debug, PartialEq, Eq)]
pub enum QueryMsg {
- $($name(String)),*
+ $($name(Option<String>)),*
}
impl<$tcx> Query<$tcx> {
span);
profq_msg!(tcx,
- ProfileQueriesMsg::QueryBegin(span.clone(),
- QueryMsg::$name(format!("{:?}", key))));
+ ProfileQueriesMsg::QueryBegin(
+ span.clone(),
+ QueryMsg::$name(profq_key!(tcx, key))
+ )
+ );
if let Some(&(ref result, dep_node_index)) = tcx.maps.$name.borrow().map.get(&key) {
tcx.dep_graph.read_index(dep_node_index);
sess.abort_if_errors();
}
- if sess.opts.debugging_opts.profile_queries {
+ if sess.profile_queries() {
profile::begin();
}
-> PResult<'a, ast::Crate> {
sess.diagnostic().set_continue_after_error(control.continue_parse_after_error);
- if sess.opts.debugging_opts.profile_queries {
+ if sess.profile_queries() {
profile::begin();
}
"translation",
move || trans::trans_crate(tcx, analysis, incremental_hashes_map, output_filenames));
- if tcx.sess.opts.debugging_opts.profile_queries {
+ if tcx.sess.profile_queries() {
profile::dump("profile_queries".to_string())
}
// option. This file may not be copied, modified, or distributed
// except according to those terms.
-use std::time::{Instant};
use rustc::util::common::{ProfQDumpParams, ProfileQueriesMsg, profq_msg, profq_set_chan};
use std::sync::mpsc::{Receiver};
use std::io::{Write};
use rustc::dep_graph::{DepNode};
+use std::time::{Duration, Instant};
pub mod trace;
path, ack:tx,
// FIXME: Add another compiler flag to toggle whether this log
// is written; false for now
- dump_profq_msg_log:false,
+ dump_profq_msg_log:true,
};
profq_msg(ProfileQueriesMsg::Dump(params));
let _ = rx.recv().unwrap();
pub traces: Vec<trace::Rec>,
}
+fn total_duration(traces: &Vec<trace::Rec>) -> Duration {
+ let mut sum : Duration = Duration::new(0,0);
+ for t in traces.iter() { sum += t.dur_total; }
+ return sum
+}
+
// profiling thread; retains state (in local variables) and dump traces, upon request.
fn profile_queries_thread(r:Receiver<ProfileQueriesMsg>) {
use self::trace::*;
parse_st:ParseState::Clear,
traces:old_frame.traces
};
+ let dur_extent = total_duration(&provider_extent);
let trace = Rec {
effect: Effect::QueryBegin(q, CacheCase::Miss),
extent: Box::new(provider_extent),
start: start,
- duration: duration,
+ dur_self: duration - dur_extent,
+ dur_total: duration,
};
frame.traces.push( trace );
},
parse_st:ParseState::Clear,
traces:old_frame.traces
};
+ let dur_extent = total_duration(&provider_extent);
let trace = Rec {
effect: Effect::TimeBegin(msg),
extent: Box::new(provider_extent),
start: start,
- duration: duration,
+ dur_total: duration,
+ dur_self: duration - dur_extent,
};
frame.traces.push( trace );
},
parse_st:ParseState::Clear,
traces:old_frame.traces
};
+ let dur_extent = total_duration(&provider_extent);
let trace = Rec {
effect: Effect::TaskBegin(key),
extent: Box::new(provider_extent),
start: start,
- duration: duration,
+ dur_total: duration,
+ dur_self: duration - dur_extent,
};
frame.traces.push( trace );
},
effect: Effect::QueryBegin(q, CacheCase::Hit),
extent: Box::new(vec![]),
start: start,
- duration: duration,
+ dur_self: duration,
+ dur_total: duration,
};
frame.traces.push( trace );
frame.parse_st = ParseState::Clear;
pub struct Rec {
pub effect: Effect,
pub start: Instant,
- pub duration: Duration,
+ pub dur_self: Duration,
+ pub dur_total: Duration,
pub extent: Box<Vec<Rec>>,
}
pub struct QueryMetric {
pub count: usize,
- pub duration: Duration,
+ pub dur_self: Duration,
+ pub dur_total: Duration,
}
pub fn cons_of_query_msg(q: &trace::Query) -> String {
fn total_duration(traces: &Vec<Rec>) -> Duration {
let mut sum : Duration = Duration::new(0,0);
for t in traces.iter() {
- sum += t.duration;
+ sum += t.dur_total;
}
return sum
}
fn write_traces_rec(file: &mut File, traces: &Vec<Rec>, total: Duration, depth: usize) {
for t in traces {
let (eff_text, eff_css_classes) = html_of_effect(&t.effect);
- let (dur_text, dur_css_classes) = html_of_duration(&t.start, &t.duration);
- let fraction = duration_div(t.duration, total);
+ let (dur_text, dur_css_classes) = html_of_duration(&t.start, &t.dur_total);
+ let fraction = duration_div(t.dur_total, total);
let percent = fraction * 100.0;
let (frc_text, frc_css_classes) = html_of_fraction(fraction);
write!(file, "<div class=\"trace depth-{} extent-{}{} {} {} {}\">\n",
Some(_qm) => { panic!("TimeBegin with non-unique, repeat message") }
None => QueryMetric{
count: 1,
- duration: t.duration
+ dur_self: t.dur_self,
+ dur_total: t.dur_total,
}};
counts.insert(msg.clone(), qm);
},
Some(qm) =>
QueryMetric{
count: qm.count + 1,
- duration: qm.duration + t.duration
+ dur_self: qm.dur_self + t.dur_self,
+ dur_total: qm.dur_total + t.dur_total,
},
None => QueryMetric{
count: 1,
- duration: t.duration
+ dur_self: t.dur_self,
+ dur_total: t.dur_total,
}};
counts.insert(cons, qm);
},
Some(qm) =>
QueryMetric{
count: qm.count + 1,
- duration: qm.duration + t.duration
+ dur_total: qm.dur_total + t.dur_total,
+ dur_self: qm.dur_self + t.dur_self
},
None => QueryMetric{
count: 1,
- duration: t.duration
+ dur_total: t.dur_total,
+ dur_self: t.dur_self,
}
};
counts.insert(qcons, qm);
let mut data = vec![];
for (ref cons, ref qm) in counts.iter() {
- data.push((cons.clone(), qm.count.clone(), qm.duration.clone()));
+ data.push((cons.clone(), qm.count.clone(), qm.dur_total.clone(), qm.dur_self.clone()));
};
- data.sort_by(|&(_,_,d1),&(_,_,d2)|
- if d1 > d2 { Ordering::Less } else { Ordering::Greater } );
- for (cons, count, duration) in data {
- write!(count_file, "{},{},{}\n",
- cons, count, duration_to_secs_str(duration)
+ data.sort_by(|&(_,_,_,self1),&(_,_,_,self2)|
+ if self1 > self2 { Ordering::Less } else { Ordering::Greater } );
+ for (cons, count, dur_total, dur_self) in data {
+ write!(count_file, "{}, {}, {}, {}\n",
+ cons, count,
+ duration_to_secs_str(dur_total),
+ duration_to_secs_str(dur_self)
).unwrap();
}
}