src/librustc_driver/profile/mod.rs - third_party/rust - Git at Google

 // Copyright 2012-2015 The Rust Project Developers. See the COPYRIGHT
 // file at the top-level directory of this distribution and at
 // http://rust-lang.org/COPYRIGHT.
 //
 // Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
 // http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
 // <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
 // option. This file may not be copied, modified, or distributed
 // except according to those terms.

 use rustc::session::Session;
 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;

 /// begin a profile thread, if not already running
 pub fn begin(sess: &Session) {
     use std::thread;
     use std::sync::mpsc::{channel};
     let (tx, rx) = channel();
     if profq_set_chan(sess, tx) {
         thread::spawn(move || profile_queries_thread(rx));
     }
 }

 /// dump files with profiling information to the given base path, and
 /// wait for this dump to complete.
 ///
 /// wraps the RPC (send/recv channel logic) of requesting a dump.
 pub fn dump(sess: &Session, path: String) {
     use std::sync::mpsc::{channel};
     let (tx, rx) = channel();
     let params = ProfQDumpParams {
         path,
         ack: tx,
         // FIXME: Add another compiler flag to toggle whether this log
         // is written; false for now
         dump_profq_msg_log: true,
     };
     profq_msg(sess, ProfileQueriesMsg::Dump(params));
     let _ = rx.recv().unwrap();
 }

 // State for parsing recursive trace structure in separate thread, via messages
 #[derive(Clone, Eq, PartialEq)]
 enum ParseState {
     // No (local) parse state; may be parsing a tree, focused on a
     // sub-tree that could be anything.
     Clear,
     // Have Query information from the last message
     HaveQuery(trace::Query, Instant),
     // Have "time-begin" information from the last message (doit flag, and message)
     HaveTimeBegin(String, Instant),
     // Have "task-begin" information from the last message
     HaveTaskBegin(DepNode, Instant),
 }
 struct StackFrame {
     pub parse_st: ParseState,
     pub traces:   Vec<trace::Rec>,
 }

 fn total_duration(traces: &[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::*;
     use std::fs::File;
     use std::time::{Instant};

     let mut profq_msgs: Vec<ProfileQueriesMsg> = vec![];
     let mut frame: StackFrame = StackFrame { parse_st: ParseState::Clear, traces: vec![] };
     let mut stack: Vec<StackFrame> = vec![];
     loop {
         let msg = r.recv();
         if let Err(_recv_err) = msg {
             // FIXME: Perhaps do something smarter than simply quitting?
             break
         };
         let msg = msg.unwrap();
         debug!("profile_queries_thread: {:?}", msg);

         // Meta-level versus _actual_ queries messages
         match msg {
             ProfileQueriesMsg::Halt => return,
             ProfileQueriesMsg::Dump(params) => {
                 assert!(stack.is_empty());
                 assert!(frame.parse_st == ParseState::Clear);
                 {
                     // write log of all messages
                     if params.dump_profq_msg_log {
                         let mut log_file =
                             File::create(format!("{}.log.txt", params.path)).unwrap();
                         for m in profq_msgs.iter() {
                             writeln!(&mut log_file, "{:?}", m).unwrap()
                         };
                     }

                     // write HTML file, and counts file
                     let html_path = format!("{}.html", params.path);
                     let mut html_file = File::create(&html_path).unwrap();

                     let counts_path = format!("{}.counts.txt", params.path);
                     let mut counts_file = File::create(&counts_path).unwrap();

                     writeln!(html_file,
                         "<html>\n<head>\n<link rel=\"stylesheet\" type=\"text/css\" href=\"{}\">",
                         "profile_queries.css").unwrap();
                     writeln!(html_file, "<style>").unwrap();
                     trace::write_style(&mut html_file);
                     writeln!(html_file, "</style>\n</head>\n<body>").unwrap();
                     trace::write_traces(&mut html_file, &mut counts_file, &frame.traces);
                     writeln!(html_file, "</body>\n</html>").unwrap();

                     let ack_path = format!("{}.ack", params.path);
                     let ack_file = File::create(&ack_path).unwrap();
                     drop(ack_file);

                     // Tell main thread that we are done, e.g., so it can exit
                     params.ack.send(()).unwrap();
                 }
                 continue
             }
             // Actual query message:
             msg => {
                 // Record msg in our log
                 profq_msgs.push(msg.clone());
                 // Respond to the message, knowing that we've already handled Halt and Dump, above.
                 match (frame.parse_st.clone(), msg) {
                     (_,ProfileQueriesMsg::Halt) => unreachable!(),
                     (_,ProfileQueriesMsg::Dump(_)) => unreachable!(),

                     // Parse State: Clear
                     (ParseState::Clear,
                      ProfileQueriesMsg::QueryBegin(span, querymsg)) => {
                         let start = Instant::now();
                         frame.parse_st = ParseState::HaveQuery
                             (Query { span, msg: querymsg }, start)
                     },
                     (ParseState::Clear,
                      ProfileQueriesMsg::CacheHit) => {
                         panic!("parse error: unexpected CacheHit; expected QueryBegin")
                     },
                     (ParseState::Clear,
                      ProfileQueriesMsg::ProviderBegin) => {
                         panic!("parse error: expected QueryBegin before beginning a provider")
                     },
                     (ParseState::Clear,
                      ProfileQueriesMsg::ProviderEnd) => {
                         let provider_extent = frame.traces;
                         match stack.pop() {
                             None =>
                                 panic!("parse error: expected a stack frame; found an empty stack"),
                             Some(old_frame) => {
                                 match old_frame.parse_st {
                                     ParseState::HaveQuery(q, start) => {
                                         let duration = start.elapsed();
                                         frame = StackFrame{
                                             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,
                                             dur_self: duration - dur_extent,
                                             dur_total: duration,
                                         };
                                         frame.traces.push( trace );
                                     },
                                     _ => panic!("internal parse error: malformed parse stack")
                                 }
                             }
                         }
                     },


                     (ParseState::Clear,
                      ProfileQueriesMsg::TimeBegin(msg)) => {
                         let start = Instant::now();
                         frame.parse_st = ParseState::HaveTimeBegin(msg, start);
                         stack.push(frame);
                         frame = StackFrame{parse_st:ParseState::Clear, traces:vec![]};
                     },
                     (_, ProfileQueriesMsg::TimeBegin(_)) =>
                         panic!("parse error; did not expect time begin here"),

                     (ParseState::Clear,
                      ProfileQueriesMsg::TimeEnd) => {
                         let provider_extent = frame.traces;
                         match stack.pop() {
                             None =>
                                 panic!("parse error: expected a stack frame; found an empty stack"),
                             Some(old_frame) => {
                                 match old_frame.parse_st {
                                     ParseState::HaveTimeBegin(msg, start) => {
                                         let duration = start.elapsed();
                                         frame = StackFrame{
                                             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,
                                             dur_total: duration,
                                             dur_self: duration - dur_extent,
                                         };
                                         frame.traces.push( trace );
                                     },
                                     _ => panic!("internal parse error: malformed parse stack")
                                 }
                             }
                         }
                     },
                     (_, ProfileQueriesMsg::TimeEnd) => { panic!("parse error") }

                     (ParseState::Clear,
                      ProfileQueriesMsg::TaskBegin(key)) => {
                         let start = Instant::now();
                         frame.parse_st = ParseState::HaveTaskBegin(key, start);
                         stack.push(frame);
                         frame = StackFrame{parse_st:ParseState::Clear, traces:vec![]};
                     },
                     (_, ProfileQueriesMsg::TaskBegin(_)) =>
                         panic!("parse error; did not expect time begin here"),

                     (ParseState::Clear,
                      ProfileQueriesMsg::TaskEnd) => {
                         let provider_extent = frame.traces;
                         match stack.pop() {
                             None =>
                                 panic!("parse error: expected a stack frame; found an empty stack"),
                             Some(old_frame) => {
                                 match old_frame.parse_st {
                                     ParseState::HaveTaskBegin(key, start) => {
                                         let duration = start.elapsed();
                                         frame = StackFrame{
                                             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,
                                             dur_total: duration,
                                             dur_self: duration - dur_extent,
                                         };
                                         frame.traces.push( trace );
                                     },
                                     _ => panic!("internal parse error: malformed parse stack")
                                 }
                             }
                         }
                     },
                     (_, ProfileQueriesMsg::TaskEnd) => { panic!("parse error") }

                     // Parse State: HaveQuery
                     (ParseState::HaveQuery(q,start),
                      ProfileQueriesMsg::CacheHit) => {
                         let duration = start.elapsed();
                         let trace : Rec = Rec{
                             effect: Effect::QueryBegin(q, CacheCase::Hit),
                             extent: Box::new(vec![]),
                             start: start,
                             dur_self: duration,
                             dur_total: duration,
                         };
                         frame.traces.push( trace );
                         frame.parse_st = ParseState::Clear;
                     },
                     (ParseState::HaveQuery(_,_),
                      ProfileQueriesMsg::ProviderBegin) => {
                         stack.push(frame);
                         frame = StackFrame{parse_st:ParseState::Clear, traces:vec![]};
                     },

                     // Parse errors:

                     (ParseState::HaveQuery(q,_),
                      ProfileQueriesMsg::ProviderEnd) => {
                         panic!("parse error: unexpected ProviderEnd; \
                                 expected something else to follow BeginQuery for {:?}", q)
                     },
                     (ParseState::HaveQuery(q1,_),
                      ProfileQueriesMsg::QueryBegin(span2,querymsg2)) => {
                         panic!("parse error: unexpected QueryBegin; \
                                 earlier query is unfinished: {:?} and now {:?}",
                                q1, Query{span:span2, msg:querymsg2})
                     },

                     (ParseState::HaveTimeBegin(_, _), _) => {
                         unreachable!()
                     },
                     (ParseState::HaveTaskBegin(_, _), _) => {
                         unreachable!()
                     },
                 }
             }
         }
     }
 }
	// Copyright 2012-2015 The Rust Project Developers. See the COPYRIGHT
	// file at the top-level directory of this distribution and at
	// http://rust-lang.org/COPYRIGHT.
	//
	// Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
	// http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
	// <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
	// option. This file may not be copied, modified, or distributed
	// except according to those terms.

	use rustc::session::Session;
	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;

	/// begin a profile thread, if not already running
	pub fn begin(sess: &Session) {
	use std::thread;
	use std::sync::mpsc::{channel};
	let (tx, rx) = channel();
	if profq_set_chan(sess, tx) {
	thread::spawn(move \|\| profile_queries_thread(rx));
	}
	}

	/// dump files with profiling information to the given base path, and
	/// wait for this dump to complete.
	///
	/// wraps the RPC (send/recv channel logic) of requesting a dump.
	pub fn dump(sess: &Session, path: String) {
	use std::sync::mpsc::{channel};
	let (tx, rx) = channel();
	let params = ProfQDumpParams {
	path,
	ack: tx,
	// FIXME: Add another compiler flag to toggle whether this log
	// is written; false for now
	dump_profq_msg_log: true,
	};
	profq_msg(sess, ProfileQueriesMsg::Dump(params));
	let _ = rx.recv().unwrap();
	}

	// State for parsing recursive trace structure in separate thread, via messages
	#[derive(Clone, Eq, PartialEq)]
	enum ParseState {
	// No (local) parse state; may be parsing a tree, focused on a
	// sub-tree that could be anything.
	Clear,
	// Have Query information from the last message
	HaveQuery(trace::Query, Instant),
	// Have "time-begin" information from the last message (doit flag, and message)
	HaveTimeBegin(String, Instant),
	// Have "task-begin" information from the last message
	HaveTaskBegin(DepNode, Instant),
	}
	struct StackFrame {
	pub parse_st: ParseState,
	pub traces: Vec<trace::Rec>,
	}

	fn total_duration(traces: &[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::*;
	use std::fs::File;
	use std::time::{Instant};

	let mut profq_msgs: Vec<ProfileQueriesMsg> = vec![];
	let mut frame: StackFrame = StackFrame { parse_st: ParseState::Clear, traces: vec![] };
	let mut stack: Vec<StackFrame> = vec![];
	loop {
	let msg = r.recv();
	if let Err(_recv_err) = msg {
	// FIXME: Perhaps do something smarter than simply quitting?
	break
	};
	let msg = msg.unwrap();
	debug!("profile_queries_thread: {:?}", msg);

	// Meta-level versus _actual_ queries messages
	match msg {
	ProfileQueriesMsg::Halt => return,
	ProfileQueriesMsg::Dump(params) => {
	assert!(stack.is_empty());
	assert!(frame.parse_st == ParseState::Clear);
	{
	// write log of all messages
	if params.dump_profq_msg_log {
	let mut log_file =
	File::create(format!("{}.log.txt", params.path)).unwrap();
	for m in profq_msgs.iter() {
	writeln!(&mut log_file, "{:?}", m).unwrap()
	};
	}

	// write HTML file, and counts file
	let html_path = format!("{}.html", params.path);
	let mut html_file = File::create(&html_path).unwrap();

	let counts_path = format!("{}.counts.txt", params.path);
	let mut counts_file = File::create(&counts_path).unwrap();

	writeln!(html_file,
	"<html>\n<head>\n<link rel=\"stylesheet\" type=\"text/css\" href=\"{}\">",
	"profile_queries.css").unwrap();
	writeln!(html_file, "<style>").unwrap();
	trace::write_style(&mut html_file);
	writeln!(html_file, "</style>\n</head>\n<body>").unwrap();
	trace::write_traces(&mut html_file, &mut counts_file, &frame.traces);
	writeln!(html_file, "</body>\n</html>").unwrap();

	let ack_path = format!("{}.ack", params.path);
	let ack_file = File::create(&ack_path).unwrap();
	drop(ack_file);

	// Tell main thread that we are done, e.g., so it can exit
	params.ack.send(()).unwrap();
	}
	continue
	}
	// Actual query message:
	msg => {
	// Record msg in our log
	profq_msgs.push(msg.clone());
	// Respond to the message, knowing that we've already handled Halt and Dump, above.
	match (frame.parse_st.clone(), msg) {
	(_,ProfileQueriesMsg::Halt) => unreachable!(),
	(_,ProfileQueriesMsg::Dump(_)) => unreachable!(),

	// Parse State: Clear
	(ParseState::Clear,
	ProfileQueriesMsg::QueryBegin(span, querymsg)) => {
	let start = Instant::now();
	frame.parse_st = ParseState::HaveQuery
	(Query { span, msg: querymsg }, start)
	},
	(ParseState::Clear,
	ProfileQueriesMsg::CacheHit) => {
	panic!("parse error: unexpected CacheHit; expected QueryBegin")
	},
	(ParseState::Clear,
	ProfileQueriesMsg::ProviderBegin) => {
	panic!("parse error: expected QueryBegin before beginning a provider")
	},
	(ParseState::Clear,
	ProfileQueriesMsg::ProviderEnd) => {
	let provider_extent = frame.traces;
	match stack.pop() {
	None =>
	panic!("parse error: expected a stack frame; found an empty stack"),
	Some(old_frame) => {
	match old_frame.parse_st {
	ParseState::HaveQuery(q, start) => {
	let duration = start.elapsed();
	frame = StackFrame{
	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,
	dur_self: duration - dur_extent,
	dur_total: duration,
	};
	frame.traces.push( trace );
	},
	_ => panic!("internal parse error: malformed parse stack")
	}
	}
	}
	},


	(ParseState::Clear,
	ProfileQueriesMsg::TimeBegin(msg)) => {
	let start = Instant::now();
	frame.parse_st = ParseState::HaveTimeBegin(msg, start);
	stack.push(frame);
	frame = StackFrame{parse_st:ParseState::Clear, traces:vec![]};
	},
	(_, ProfileQueriesMsg::TimeBegin(_)) =>
	panic!("parse error; did not expect time begin here"),

	(ParseState::Clear,
	ProfileQueriesMsg::TimeEnd) => {
	let provider_extent = frame.traces;
	match stack.pop() {
	None =>
	panic!("parse error: expected a stack frame; found an empty stack"),
	Some(old_frame) => {
	match old_frame.parse_st {
	ParseState::HaveTimeBegin(msg, start) => {
	let duration = start.elapsed();
	frame = StackFrame{
	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,
	dur_total: duration,
	dur_self: duration - dur_extent,
	};
	frame.traces.push( trace );
	},
	_ => panic!("internal parse error: malformed parse stack")
	}
	}
	}
	},
	(_, ProfileQueriesMsg::TimeEnd) => { panic!("parse error") }

	(ParseState::Clear,
	ProfileQueriesMsg::TaskBegin(key)) => {
	let start = Instant::now();
	frame.parse_st = ParseState::HaveTaskBegin(key, start);
	stack.push(frame);
	frame = StackFrame{parse_st:ParseState::Clear, traces:vec![]};
	},
	(_, ProfileQueriesMsg::TaskBegin(_)) =>
	panic!("parse error; did not expect time begin here"),

	(ParseState::Clear,
	ProfileQueriesMsg::TaskEnd) => {
	let provider_extent = frame.traces;
	match stack.pop() {
	None =>
	panic!("parse error: expected a stack frame; found an empty stack"),
	Some(old_frame) => {
	match old_frame.parse_st {
	ParseState::HaveTaskBegin(key, start) => {
	let duration = start.elapsed();
	frame = StackFrame{
	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,
	dur_total: duration,
	dur_self: duration - dur_extent,
	};
	frame.traces.push( trace );
	},
	_ => panic!("internal parse error: malformed parse stack")
	}
	}
	}
	},
	(_, ProfileQueriesMsg::TaskEnd) => { panic!("parse error") }

	// Parse State: HaveQuery
	(ParseState::HaveQuery(q,start),
	ProfileQueriesMsg::CacheHit) => {
	let duration = start.elapsed();
	let trace : Rec = Rec{
	effect: Effect::QueryBegin(q, CacheCase::Hit),
	extent: Box::new(vec![]),
	start: start,
	dur_self: duration,
	dur_total: duration,
	};
	frame.traces.push( trace );
	frame.parse_st = ParseState::Clear;
	},
	(ParseState::HaveQuery(_,_),
	ProfileQueriesMsg::ProviderBegin) => {
	stack.push(frame);
	frame = StackFrame{parse_st:ParseState::Clear, traces:vec![]};
	},

	// Parse errors:

	(ParseState::HaveQuery(q,_),
	ProfileQueriesMsg::ProviderEnd) => {
	panic!("parse error: unexpected ProviderEnd; \
	expected something else to follow BeginQuery for {:?}", q)
	},
	(ParseState::HaveQuery(q1,_),
	ProfileQueriesMsg::QueryBegin(span2,querymsg2)) => {
	panic!("parse error: unexpected QueryBegin; \
	earlier query is unfinished: {:?} and now {:?}",
	q1, Query{span:span2, msg:querymsg2})
	},

	(ParseState::HaveTimeBegin(_, _), _) => {
	unreachable!()
	},
	(ParseState::HaveTaskBegin(_, _), _) => {
	unreachable!()
	},
	}
	}
	}
	}
	}