1 use rustc::session::Session;
2 use rustc::util::common::{ProfQDumpParams, ProfileQueriesMsg, profq_msg, profq_set_chan};
3 use std::sync::mpsc::{Receiver};
5 use rustc::dep_graph::{DepNode};
6 use std::time::{Duration, Instant};
10 /// begin a profile thread, if not already running
11 pub fn begin(sess: &Session) {
13 use std::sync::mpsc::{channel};
14 let (tx, rx) = channel();
15 if profq_set_chan(sess, tx) {
16 thread::spawn(move || profile_queries_thread(rx));
20 /// dump files with profiling information to the given base path, and
21 /// wait for this dump to complete.
23 /// wraps the RPC (send/recv channel logic) of requesting a dump.
24 pub fn dump(sess: &Session, path: String) {
25 use std::sync::mpsc::{channel};
26 let (tx, rx) = channel();
27 let params = ProfQDumpParams {
30 // FIXME: Add another compiler flag to toggle whether this log
31 // is written; false for now
32 dump_profq_msg_log: true,
34 profq_msg(sess, ProfileQueriesMsg::Dump(params));
35 let _ = rx.recv().unwrap();
38 // State for parsing recursive trace structure in separate thread, via messages
39 #[derive(Clone, Eq, PartialEq)]
41 // No (local) parse state; may be parsing a tree, focused on a
42 // sub-tree that could be anything.
44 // Have Query information from the last message
45 HaveQuery(trace::Query, Instant),
46 // Have "time-begin" information from the last message (doit flag, and message)
47 HaveTimeBegin(String, Instant),
48 // Have "task-begin" information from the last message
49 HaveTaskBegin(DepNode, Instant),
52 pub parse_st: ParseState,
53 pub traces: Vec<trace::Rec>,
56 fn total_duration(traces: &[trace::Rec]) -> Duration {
57 Duration::new(0, 0) + traces.iter().map(|t| t.dur_total).sum()
60 // profiling thread; retains state (in local variables) and dump traces, upon request.
61 fn profile_queries_thread(r: Receiver<ProfileQueriesMsg>) {
64 use std::time::{Instant};
66 let mut profq_msgs: Vec<ProfileQueriesMsg> = vec![];
67 let mut frame: StackFrame = StackFrame { parse_st: ParseState::Clear, traces: vec![] };
68 let mut stack: Vec<StackFrame> = vec![];
71 if let Err(_recv_err) = msg {
72 // FIXME: Perhaps do something smarter than simply quitting?
75 let msg = msg.unwrap();
76 debug!("profile_queries_thread: {:?}", msg);
78 // Meta-level versus _actual_ queries messages
80 ProfileQueriesMsg::Halt => return,
81 ProfileQueriesMsg::Dump(params) => {
82 assert!(stack.is_empty());
83 assert!(frame.parse_st == ParseState::Clear);
85 // write log of all messages
86 if params.dump_profq_msg_log {
88 File::create(format!("{}.log.txt", params.path)).unwrap();
89 for m in profq_msgs.iter() {
90 writeln!(&mut log_file, "{:?}", m).unwrap()
94 // write HTML file, and counts file
95 let html_path = format!("{}.html", params.path);
96 let mut html_file = File::create(&html_path).unwrap();
98 let counts_path = format!("{}.counts.txt", params.path);
99 let mut counts_file = File::create(&counts_path).unwrap();
102 "<html>\n<head>\n<link rel=\"stylesheet\" type=\"text/css\" href=\"{}\">",
103 "profile_queries.css").unwrap();
104 writeln!(html_file, "<style>").unwrap();
105 trace::write_style(&mut html_file);
106 writeln!(html_file, "</style>\n</head>\n<body>").unwrap();
107 trace::write_traces(&mut html_file, &mut counts_file, &frame.traces);
108 writeln!(html_file, "</body>\n</html>").unwrap();
110 let ack_path = format!("{}.ack", params.path);
111 let ack_file = File::create(&ack_path).unwrap();
114 // Tell main thread that we are done, e.g., so it can exit
115 params.ack.send(()).unwrap();
117 // Actual query message:
119 // Record msg in our log
120 profq_msgs.push(msg.clone());
121 // Respond to the message, knowing that we've already handled Halt and Dump, above.
122 match (frame.parse_st.clone(), msg) {
123 (_, ProfileQueriesMsg::Halt) | (_, ProfileQueriesMsg::Dump(_)) => {
126 // Parse State: Clear
128 ProfileQueriesMsg::QueryBegin(span, querymsg)) => {
129 let start = Instant::now();
130 frame.parse_st = ParseState::HaveQuery
131 (Query { span, msg: querymsg }, start)
134 ProfileQueriesMsg::CacheHit) => {
135 panic!("parse error: unexpected CacheHit; expected QueryBegin")
138 ProfileQueriesMsg::ProviderBegin) => {
139 panic!("parse error: expected QueryBegin before beginning a provider")
142 ProfileQueriesMsg::ProviderEnd) => {
143 let provider_extent = frame.traces;
146 panic!("parse error: expected a stack frame; found an empty stack"),
148 match old_frame.parse_st {
149 ParseState::HaveQuery(q, start) => {
150 let duration = start.elapsed();
152 parse_st: ParseState::Clear,
153 traces: old_frame.traces
155 let dur_extent = total_duration(&provider_extent);
157 effect: Effect::QueryBegin(q, CacheCase::Miss),
158 extent: Box::new(provider_extent),
160 dur_self: duration - dur_extent,
163 frame.traces.push( trace );
165 _ => panic!("internal parse error: malformed parse stack")
171 ProfileQueriesMsg::TimeBegin(msg)) => {
172 let start = Instant::now();
173 frame.parse_st = ParseState::HaveTimeBegin(msg, start);
175 frame = StackFrame{parse_st: ParseState::Clear, traces: vec![]};
177 (_, ProfileQueriesMsg::TimeBegin(_)) => {
178 panic!("parse error; did not expect time begin here");
181 ProfileQueriesMsg::TimeEnd) => {
182 let provider_extent = frame.traces;
185 panic!("parse error: expected a stack frame; found an empty stack"),
187 match old_frame.parse_st {
188 ParseState::HaveTimeBegin(msg, start) => {
189 let duration = start.elapsed();
191 parse_st: ParseState::Clear,
192 traces: old_frame.traces
194 let dur_extent = total_duration(&provider_extent);
196 effect: Effect::TimeBegin(msg),
197 extent: Box::new(provider_extent),
200 dur_self: duration - dur_extent,
202 frame.traces.push( trace );
204 _ => panic!("internal parse error: malformed parse stack")
209 (_, ProfileQueriesMsg::TimeEnd) => {
210 panic!("parse error")
213 ProfileQueriesMsg::TaskBegin(key)) => {
214 let start = Instant::now();
215 frame.parse_st = ParseState::HaveTaskBegin(key, start);
217 frame = StackFrame{ parse_st: ParseState::Clear, traces: vec![] };
219 (_, ProfileQueriesMsg::TaskBegin(_)) => {
220 panic!("parse error; did not expect time begin here");
223 ProfileQueriesMsg::TaskEnd) => {
224 let provider_extent = frame.traces;
227 panic!("parse error: expected a stack frame; found an empty stack"),
229 match old_frame.parse_st {
230 ParseState::HaveTaskBegin(key, start) => {
231 let duration = start.elapsed();
233 parse_st: ParseState::Clear,
234 traces: old_frame.traces
236 let dur_extent = total_duration(&provider_extent);
238 effect: Effect::TaskBegin(key),
239 extent: Box::new(provider_extent),
242 dur_self: duration - dur_extent,
244 frame.traces.push( trace );
246 _ => panic!("internal parse error: malformed parse stack")
251 (_, ProfileQueriesMsg::TaskEnd) => {
252 panic!("parse error")
254 // Parse State: HaveQuery
255 (ParseState::HaveQuery(q,start),
256 ProfileQueriesMsg::CacheHit) => {
257 let duration = start.elapsed();
258 let trace : Rec = Rec{
259 effect: Effect::QueryBegin(q, CacheCase::Hit),
260 extent: Box::new(vec![]),
265 frame.traces.push( trace );
266 frame.parse_st = ParseState::Clear;
268 (ParseState::HaveQuery(_, _),
269 ProfileQueriesMsg::ProviderBegin) => {
271 frame = StackFrame{ parse_st: ParseState::Clear, traces: vec![] };
276 (ParseState::HaveQuery(q, _),
277 ProfileQueriesMsg::ProviderEnd) => {
278 panic!("parse error: unexpected ProviderEnd; \
279 expected something else to follow BeginQuery for {:?}", q)
281 (ParseState::HaveQuery(q1, _),
282 ProfileQueriesMsg::QueryBegin(span2, querymsg2)) => {
283 panic!("parse error: unexpected QueryBegin; \
284 earlier query is unfinished: {:?} and now {:?}",
285 q1, Query{span:span2, msg: querymsg2})
287 (ParseState::HaveTimeBegin(_, _), _) => {
290 (ParseState::HaveTaskBegin(_, _), _) => {