Add -Z time-passes-format to allow specifying a JSON output for -Z time-passes

This commit is contained in:
John Kåre Alsaker 2023-02-06 06:32:34 +01:00
parent b0dc15c61b
commit f60d2eb6c1
12 changed files with 105 additions and 27 deletions

View file

@ -97,6 +97,7 @@ use std::time::{Duration, Instant};
pub use measureme::EventId;
use measureme::{EventIdBuilder, Profiler, SerializableString, StringId};
use parking_lot::RwLock;
use serde_json::json;
use smallvec::SmallVec;
bitflags::bitflags! {
@ -145,6 +146,15 @@ const EVENT_FILTERS_BY_NAME: &[(&str, EventFilter)] = &[
/// Something that uniquely identifies a query invocation.
pub struct QueryInvocationId(pub u32);
/// Which format to use for `-Z time-passes`
#[derive(Clone, Copy, PartialEq, Hash, Debug)]
pub enum TimePassesFormat {
/// Emit human readable text
Text,
/// Emit structured JSON
Json,
}
/// A reference to the SelfProfiler. It can be cloned and sent across thread
/// boundaries at will.
#[derive(Clone)]
@ -158,14 +168,14 @@ pub struct SelfProfilerRef {
// actually enabled.
event_filter_mask: EventFilter,
// Print verbose generic activities to stderr?
print_verbose_generic_activities: bool,
// Print verbose generic activities to stderr.
print_verbose_generic_activities: Option<TimePassesFormat>,
}
impl SelfProfilerRef {
pub fn new(
profiler: Option<Arc<SelfProfiler>>,
print_verbose_generic_activities: bool,
print_verbose_generic_activities: Option<TimePassesFormat>,
) -> SelfProfilerRef {
// If there is no SelfProfiler then the filter mask is set to NONE,
// ensuring that nothing ever tries to actually access it.
@ -207,9 +217,10 @@ impl SelfProfilerRef {
/// a measureme event, "verbose" generic activities also print a timing entry to
/// stderr if the compiler is invoked with -Ztime-passes.
pub fn verbose_generic_activity(&self, event_label: &'static str) -> VerboseTimingGuard<'_> {
let message = self.print_verbose_generic_activities.then(|| event_label.to_owned());
let message_and_format =
self.print_verbose_generic_activities.map(|format| (event_label.to_owned(), format));
VerboseTimingGuard::start(message, self.generic_activity(event_label))
VerboseTimingGuard::start(message_and_format, self.generic_activity(event_label), false)
}
/// Like `verbose_generic_activity`, but with an extra arg.
@ -221,11 +232,26 @@ impl SelfProfilerRef {
where
A: Borrow<str> + Into<String>,
{
let message = self
let message_and_format = self
.print_verbose_generic_activities
.then(|| format!("{}({})", event_label, event_arg.borrow()));
.map(|format| (format!("{}({})", event_label, event_arg.borrow()), format));
VerboseTimingGuard::start(message, self.generic_activity_with_arg(event_label, event_arg))
VerboseTimingGuard::start(
message_and_format,
self.generic_activity_with_arg(event_label, event_arg),
false,
)
}
/// Like `verbose_generic_activity`, but `event_label` must be unique for a rustc session.
pub fn unique_verbose_generic_activity(
&self,
event_label: &'static str,
) -> VerboseTimingGuard<'_> {
let message_and_format =
self.print_verbose_generic_activities.map(|format| (event_label.to_owned(), format));
VerboseTimingGuard::start(message_and_format, self.generic_activity(event_label), true)
}
/// Start profiling a generic activity. Profiling continues until the
@ -705,15 +731,21 @@ impl<'a> TimingGuard<'a> {
#[must_use]
pub struct VerboseTimingGuard<'a> {
start_and_message: Option<(Instant, Option<usize>, String)>,
start_and_message: Option<(Instant, Option<usize>, String, TimePassesFormat, bool)>,
_guard: TimingGuard<'a>,
}
impl<'a> VerboseTimingGuard<'a> {
pub fn start(message: Option<String>, _guard: TimingGuard<'a>) -> Self {
pub fn start(
message_and_format: Option<(String, TimePassesFormat)>,
_guard: TimingGuard<'a>,
unique: bool,
) -> Self {
VerboseTimingGuard {
_guard,
start_and_message: message.map(|msg| (Instant::now(), get_resident_set_size(), msg)),
start_and_message: message_and_format.map(|(msg, format)| {
(Instant::now(), get_resident_set_size(), msg, format, unique)
}),
}
}
@ -726,10 +758,10 @@ impl<'a> VerboseTimingGuard<'a> {
impl Drop for VerboseTimingGuard<'_> {
fn drop(&mut self) {
if let Some((start_time, start_rss, ref message)) = self.start_and_message {
if let Some((start_time, start_rss, ref message, format, unique)) = self.start_and_message {
let end_rss = get_resident_set_size();
let dur = start_time.elapsed();
print_time_passes_entry(message, dur, start_rss, end_rss);
print_time_passes_entry(message, dur, start_rss, end_rss, format, unique);
}
}
}
@ -739,7 +771,21 @@ pub fn print_time_passes_entry(
dur: Duration,
start_rss: Option<usize>,
end_rss: Option<usize>,
format: TimePassesFormat,
unique: bool,
) {
if format == TimePassesFormat::Json {
let json = json!({
"pass": what,
"time": dur.as_secs_f64(),
"rss_start": start_rss,
"rss_end": end_rss,
"unique": unique,
});
eprintln!("time: {}", json.to_string());
return;
}
// Print the pass if its duration is greater than 5 ms, or it changed the
// measured RSS.
let is_notable = || {