Skip to content

Commit d7ec3e1

Browse files
author
Matthew Hammer
committed
1 parent a3f0ee9 commit d7ec3e1

File tree

8 files changed

+526
-0
lines changed

8 files changed

+526
-0
lines changed

src/librustc/session/config.rs

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -995,6 +995,8 @@ options! {DebuggingOptions, DebuggingSetter, basic_debugging_options,
995995
"dump the dependency graph to $RUST_DEP_GRAPH (default: /tmp/dep_graph.gv)"),
996996
query_dep_graph: bool = (false, parse_bool, [UNTRACKED],
997997
"enable queries of the dependency graph for regression testing"),
998+
profile_queries: bool = (false, parse_bool, [UNTRACKED],
999+
"trace and profile the queries of the incremental compilation framework"),
9981000
no_analysis: bool = (false, parse_bool, [UNTRACKED],
9991001
"parse and expand the source, but run no analysis"),
10001002
extra_plugins: Vec<String> = (Vec::new(), parse_list, [TRACKED],

src/librustc/session/mod.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -389,6 +389,7 @@ impl Session {
389389
}
390390
pub fn verbose(&self) -> bool { self.opts.debugging_opts.verbose }
391391
pub fn time_passes(&self) -> bool { self.opts.debugging_opts.time_passes }
392+
pub fn profile_queries(&self) -> bool { self.opts.debugging_opts.profile_queries }
392393
pub fn count_llvm_insns(&self) -> bool {
393394
self.opts.debugging_opts.count_llvm_insns
394395
}

src/librustc/ty/maps.rs

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ use ty::steal::Steal;
2828
use ty::subst::Substs;
2929
use ty::fast_reject::SimplifiedType;
3030
use util::nodemap::{DefIdSet, NodeSet};
31+
use util::common::{profq_msg, ProfileQueriesMsg};
3132

3233
use rustc_data_structures::indexed_vec::IndexVec;
3334
use rustc_data_structures::fx::FxHashMap;
@@ -510,6 +511,16 @@ impl<'tcx> QueryDescription for queries::extern_crate<'tcx> {
510511
impl<'tcx> QueryDescription for queries::lint_levels<'tcx> {
511512
fn describe(_tcx: TyCtxt, _: CrateNum) -> String {
512513
format!("computing the lint levels for items in this crate")
514+
}
515+
516+
// If enabled, send a message to the profile-queries thread
517+
macro_rules! profq_msg {
518+
($tcx:expr, $msg:expr) => {
519+
if cfg!(debug_assertions) {
520+
if $tcx.sess.opts.debugging_opts.profile_queries {
521+
profq_msg($msg)
522+
}
523+
}
513524
}
514525
}
515526

@@ -539,6 +550,12 @@ macro_rules! define_maps {
539550
$($(#[$attr])* $name($K)),*
540551
}
541552

553+
#[allow(bad_style)]
554+
#[derive(Clone, Debug, PartialEq, Eq)]
555+
pub enum QueryMsg {
556+
$($name(String)),*
557+
}
558+
542559
impl<$tcx> Query<$tcx> {
543560
pub fn describe(&self, tcx: TyCtxt) -> String {
544561
match *self {
@@ -581,10 +598,17 @@ macro_rules! define_maps {
581598
key,
582599
span);
583600

601+
profq_msg!(tcx,
602+
ProfileQueriesMsg::QueryBegin(span.clone(),
603+
QueryMsg::$name(format!("{:?}", key))));
604+
584605
if let Some(&(ref result, dep_node_index)) = tcx.maps.$name.borrow().map.get(&key) {
585606
tcx.dep_graph.read_index(dep_node_index);
607+
profq_msg!(tcx, ProfileQueriesMsg::CacheHit);
586608
return Ok(f(result));
587609
}
610+
// else, we are going to run the provider:
611+
profq_msg!(tcx, ProfileQueriesMsg::ProviderBegin);
588612

589613
// FIXME(eddyb) Get more valid Span's on queries.
590614
// def_span guard is necessary to prevent a recursive loop,
@@ -612,6 +636,7 @@ macro_rules! define_maps {
612636
tcx.dep_graph.with_task(dep_node, tcx, key, run_provider)
613637
}
614638
})?;
639+
profq_msg!(tcx, ProfileQueriesMsg::ProviderEnd);
615640

616641
tcx.dep_graph.read_index(dep_node_index);
617642

src/librustc/util/common.rs

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,10 @@ use std::iter::repeat;
1919
use std::path::Path;
2020
use std::time::{Duration, Instant};
2121

22+
use std::sync::mpsc::{Sender};
23+
use syntax_pos::{Span};
24+
use ty::maps::{QueryMsg};
25+
2226
// The name of the associated type for `Fn` return types
2327
pub const FN_OUTPUT_NAME: &'static str = "Output";
2428

@@ -29,6 +33,59 @@ pub struct ErrorReported;
2933

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

36+
/// Initialized for -Z profile-queries
37+
thread_local!(static PROFQ_CHAN: RefCell<Option<Sender<ProfileQueriesMsg>>> = RefCell::new(None));
38+
39+
/// Parameters to the `Dump` variant of type `ProfileQueriesMsg`.
40+
#[derive(Clone,Debug)]
41+
pub struct ProfQDumpParams {
42+
/// A base path for the files we will dump
43+
pub path:String,
44+
/// To ensure that the compiler waits for us to finish our dumps
45+
pub ack:Sender<()>,
46+
/// toggle dumping a log file with every `ProfileQueriesMsg`
47+
pub dump_profq_msg_log:bool,
48+
}
49+
50+
/// A sequence of these messages induce a trace of query-based incremental compilation.
51+
/// FIXME(matthewhammer): Determine whether we should include cycle detection here or not.
52+
#[derive(Clone,Debug)]
53+
pub enum ProfileQueriesMsg {
54+
/// begin a new query
55+
QueryBegin(Span,QueryMsg),
56+
/// query is satisfied by using an already-known value for the given key
57+
CacheHit,
58+
/// query requires running a provider; providers may nest, permitting queries to nest.
59+
ProviderBegin,
60+
/// query is satisfied by a provider terminating with a value
61+
ProviderEnd,
62+
/// dump a record of the queries to the given path
63+
Dump(ProfQDumpParams),
64+
/// halt the profiling/monitoring background thread
65+
Halt
66+
}
67+
68+
/// If enabled, send a message to the profile-queries thread
69+
pub fn profq_msg(msg: ProfileQueriesMsg) {
70+
PROFQ_CHAN.with(|sender|{
71+
if let Some(s) = sender.borrow().as_ref() {
72+
s.send(msg).unwrap()
73+
} else {
74+
panic!("no channel on which to send profq_msg: {:?}", msg)
75+
}
76+
})
77+
}
78+
79+
/// Set channel for profile queries channel
80+
pub fn profq_set_chan(s: Sender<ProfileQueriesMsg>) -> bool {
81+
PROFQ_CHAN.with(|chan|{
82+
if chan.borrow().is_none() {
83+
*chan.borrow_mut() = Some(s);
84+
true
85+
} else { false }
86+
})
87+
}
88+
3289
/// Read the current depth of `time()` calls. This is used to
3390
/// encourage indentation across threads.
3491
pub fn time_depth() -> usize {

src/librustc_driver/driver.rs

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,8 @@ use arena::DroplessArena;
6464

6565
use derive_registrar;
6666

67+
use profile;
68+
6769
pub fn compile_input(sess: &Session,
6870
cstore: &CStore,
6971
input: &Input,
@@ -105,6 +107,10 @@ pub fn compile_input(sess: &Session,
105107
sess.abort_if_errors();
106108
}
107109

110+
if sess.opts.debugging_opts.profile_queries {
111+
profile::begin();
112+
}
113+
108114
// We need nested scopes here, because the intermediate results can keep
109115
// large chunks of memory alive and we want to free them as soon as
110116
// possible to keep the peak memory usage low
@@ -537,6 +543,10 @@ pub fn phase_1_parse_input<'a>(control: &CompileController,
537543
-> PResult<'a, ast::Crate> {
538544
sess.diagnostic().set_continue_after_error(control.continue_parse_after_error);
539545

546+
if sess.opts.debugging_opts.profile_queries {
547+
profile::begin();
548+
}
549+
540550
let krate = time(sess.time_passes(), "parsing", || {
541551
match *input {
542552
Input::File(ref file) => {
@@ -1120,6 +1130,10 @@ pub fn phase_4_translate_to_llvm<'a, 'tcx>(tcx: TyCtxt<'a, 'tcx, 'tcx>,
11201130
"translation",
11211131
move || trans::trans_crate(tcx, analysis, incremental_hashes_map, output_filenames));
11221132

1133+
if tcx.sess.opts.debugging_opts.profile_queries {
1134+
profile::dump("profile_queries".to_string())
1135+
}
1136+
11231137
translation
11241138
}
11251139

src/librustc_driver/lib.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -104,6 +104,7 @@ use syntax_pos::{DUMMY_SP, MultiSpan};
104104
#[cfg(test)]
105105
mod test;
106106

107+
pub mod profile;
107108
pub mod driver;
108109
pub mod pretty;
109110
pub mod target_features;

src/librustc_driver/profile/mod.rs

Lines changed: 188 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,188 @@
1+
// Copyright 2012-2015 The Rust Project Developers. See the COPYRIGHT
2+
// file at the top-level directory of this distribution and at
3+
// http://rust-lang.org/COPYRIGHT.
4+
//
5+
// Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
6+
// http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
7+
// <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
8+
// option. This file may not be copied, modified, or distributed
9+
// except according to those terms.
10+
11+
use rustc::util::common::{ProfQDumpParams, ProfileQueriesMsg, profq_msg, profq_set_chan};
12+
use std::sync::mpsc::{Receiver};
13+
use std::io::{Write};
14+
15+
pub mod trace;
16+
17+
/// begin a profile thread, if not already running
18+
pub fn begin() {
19+
use std::thread;
20+
use std::sync::mpsc::{channel};
21+
let (tx, rx) = channel();
22+
if profq_set_chan(tx) {
23+
thread::spawn(move||profile_queries_thread(rx));
24+
}
25+
}
26+
27+
/// dump files with profiling information to the given base path, and
28+
/// wait for this dump to complete.
29+
///
30+
/// wraps the RPC (send/recv channel logic) of requesting a dump.
31+
pub fn dump(path:String) {
32+
use std::sync::mpsc::{channel};
33+
let (tx, rx) = channel();
34+
let params = ProfQDumpParams{
35+
path, ack:tx,
36+
// FIXME: Add another compiler flag to toggle whether this log
37+
// is written; false for now
38+
dump_profq_msg_log:false,
39+
};
40+
profq_msg(ProfileQueriesMsg::Dump(params));
41+
let _ = rx.recv().unwrap();
42+
}
43+
44+
// profiling thread; retains state (in local variables) and dump traces, upon request.
45+
fn profile_queries_thread(r:Receiver<ProfileQueriesMsg>) {
46+
use self::trace::*;
47+
use std::fs::File;
48+
use std::time::{Instant};
49+
50+
let mut profq_msgs : Vec<ProfileQueriesMsg> = vec![];
51+
let mut frame : StackFrame = StackFrame{ parse_st:ParseState::NoQuery, traces:vec![] };
52+
let mut stack : Vec<StackFrame> = vec![];
53+
loop {
54+
let msg = r.recv();
55+
if let Err(_recv_err) = msg {
56+
// FIXME: Perhaps do something smarter than simply quitting?
57+
break
58+
};
59+
let msg = msg.unwrap();
60+
debug!("profile_queries_thread: {:?}", msg);
61+
62+
// Meta-level versus _actual_ queries messages
63+
match msg {
64+
ProfileQueriesMsg::Halt => return,
65+
ProfileQueriesMsg::Dump(params) => {
66+
assert!(stack.len() == 0);
67+
assert!(frame.parse_st == trace::ParseState::NoQuery);
68+
{
69+
// write log of all messages
70+
if params.dump_profq_msg_log {
71+
let mut log_file =
72+
File::create(format!("{}.log.txt", params.path)).unwrap();
73+
for m in profq_msgs.iter() {
74+
writeln!(&mut log_file, "{:?}", m).unwrap()
75+
};
76+
}
77+
78+
// write HTML file, and counts file
79+
let html_path = format!("{}.html", params.path);
80+
let mut html_file = File::create(&html_path).unwrap();
81+
82+
let counts_path = format!("{}.counts.txt", params.path);
83+
let mut counts_file = File::create(&counts_path).unwrap();
84+
85+
write!(html_file, "<html>\n").unwrap();
86+
write!(html_file,
87+
"<head>\n<link rel=\"stylesheet\" type=\"text/css\" href=\"{}\">\n",
88+
"profile_queries.css").unwrap();
89+
write!(html_file, "<style>\n").unwrap();
90+
trace::write_style(&mut html_file);
91+
write!(html_file, "</style>\n").unwrap();
92+
write!(html_file, "</head>\n").unwrap();
93+
write!(html_file, "<body>\n").unwrap();
94+
trace::write_traces(&mut html_file, &mut counts_file, &frame.traces);
95+
write!(html_file, "</body>\n</html>\n").unwrap();
96+
97+
// Tell main thread that we are done, e.g., so it can exit
98+
params.ack.send(()).unwrap();
99+
}
100+
continue
101+
}
102+
// Actual query message:
103+
msg => {
104+
// Record msg in our log
105+
profq_msgs.push(msg.clone());
106+
// Respond to the message, knowing that we've already handled Halt and Dump, above.
107+
match (frame.parse_st.clone(), msg) {
108+
(_,ProfileQueriesMsg::Halt) => unreachable!(),
109+
(_,ProfileQueriesMsg::Dump(_)) => unreachable!(),
110+
111+
// Parse State: NoQuery
112+
(ParseState::NoQuery,
113+
ProfileQueriesMsg::QueryBegin(span,querymsg)) => {
114+
let start = Instant::now();
115+
frame.parse_st = ParseState::HaveQuery
116+
(Query{span:span, msg:querymsg}, start)
117+
},
118+
(ParseState::NoQuery,
119+
ProfileQueriesMsg::CacheHit) => {
120+
panic!("parse error: unexpected CacheHit; expected QueryBegin")
121+
},
122+
(ParseState::NoQuery,
123+
ProfileQueriesMsg::ProviderBegin) => {
124+
panic!("parse error: expected QueryBegin before beginning a provider")
125+
},
126+
(ParseState::NoQuery,
127+
ProfileQueriesMsg::ProviderEnd) => {
128+
let provider_extent = frame.traces;
129+
match stack.pop() {
130+
None =>
131+
panic!("parse error: expected a stack frame; found an empty stack"),
132+
Some(old_frame) => {
133+
match old_frame.parse_st {
134+
ParseState::NoQuery =>
135+
panic!("parse error: expected a stack frame for a query"),
136+
ParseState::HaveQuery(q,start) => {
137+
let duration = start.elapsed();
138+
frame = StackFrame{
139+
parse_st:ParseState::NoQuery,
140+
traces:old_frame.traces
141+
};
142+
let trace = Rec {
143+
effect: Effect::QueryBegin(q, CacheCase::Miss),
144+
extent: Box::new(provider_extent),
145+
start: start,
146+
duration: duration,
147+
};
148+
frame.traces.push( trace );
149+
}
150+
}
151+
}
152+
}
153+
}
154+
155+
// Parse State: HaveQuery
156+
(ParseState::HaveQuery(q,start),
157+
ProfileQueriesMsg::CacheHit) => {
158+
let duration = start.elapsed();
159+
let trace : Rec = Rec{
160+
effect: Effect::QueryBegin(q, CacheCase::Hit),
161+
extent: Box::new(vec![]),
162+
start: start,
163+
duration: duration,
164+
};
165+
frame.traces.push( trace );
166+
frame.parse_st = ParseState::NoQuery;
167+
},
168+
(ParseState::HaveQuery(_,_),
169+
ProfileQueriesMsg::ProviderBegin) => {
170+
stack.push(frame);
171+
frame = StackFrame{parse_st:ParseState::NoQuery, traces:vec![]};
172+
},
173+
(ParseState::HaveQuery(q,_),
174+
ProfileQueriesMsg::ProviderEnd) => {
175+
panic!("parse error: unexpected ProviderEnd; \
176+
expected something else to follow BeginQuery for {:?}", q)
177+
},
178+
(ParseState::HaveQuery(q1,_),
179+
ProfileQueriesMsg::QueryBegin(span2,querymsg2)) => {
180+
panic!("parse error: unexpected QueryBegin; \
181+
earlier query is unfinished: {:?} and now {:?}",
182+
q1, Query{span:span2, msg:querymsg2})
183+
},
184+
}
185+
}
186+
}
187+
}
188+
}

0 commit comments

Comments
 (0)