pub use measureme::EventId;
use measureme::{EventIdBuilder, Profiler, SerializableString, StringId};
use parking_lot::RwLock;
+use smallvec::SmallVec;
bitflags::bitflags! {
struct EventFilter: u32 {
const FUNCTION_ARGS = 1 << 6;
const LLVM = 1 << 7;
const INCR_RESULT_HASHING = 1 << 8;
+ const ARTIFACT_SIZES = 1 << 9;
const DEFAULT = Self::GENERIC_ACTIVITIES.bits |
Self::QUERY_PROVIDERS.bits |
Self::QUERY_BLOCKED.bits |
Self::INCR_CACHE_LOADS.bits |
- Self::INCR_RESULT_HASHING.bits;
+ Self::INCR_RESULT_HASHING.bits |
+ Self::ARTIFACT_SIZES.bits;
const ARGS = Self::QUERY_KEYS.bits | Self::FUNCTION_ARGS.bits;
}
("args", EventFilter::ARGS),
("llvm", EventFilter::LLVM),
("incr-result-hashing", EventFilter::INCR_RESULT_HASHING),
+ ("artifact-sizes", EventFilter::ARTIFACT_SIZES),
];
/// Something that uniquely identifies a query invocation.
// actually enabled.
event_filter_mask: EventFilter,
- // Print verbose generic activities to stdout
+ // Print verbose generic activities to stderr?
print_verbose_generic_activities: bool,
-
- // Print extra verbose generic activities to stdout
- print_extra_verbose_generic_activities: bool,
}
impl SelfProfilerRef {
pub fn new(
profiler: Option<Arc<SelfProfiler>>,
print_verbose_generic_activities: bool,
- print_extra_verbose_generic_activities: bool,
) -> SelfProfilerRef {
// If there is no SelfProfiler then the filter mask is set to NONE,
// ensuring that nothing ever tries to actually access it.
let event_filter_mask =
profiler.as_ref().map_or(EventFilter::empty(), |p| p.event_filter_mask);
- SelfProfilerRef {
- profiler,
- event_filter_mask,
- print_verbose_generic_activities,
- print_extra_verbose_generic_activities,
- }
+ SelfProfilerRef { profiler, event_filter_mask, print_verbose_generic_activities }
}
- // This shim makes sure that calls only get executed if the filter mask
- // lets them pass. It also contains some trickery to make sure that
- // code is optimized for non-profiling compilation sessions, i.e. anything
- // past the filter check is never inlined so it doesn't clutter the fast
- // path.
+ /// This shim makes sure that calls only get executed if the filter mask
+ /// lets them pass. It also contains some trickery to make sure that
+ /// code is optimized for non-profiling compilation sessions, i.e. anything
+ /// past the filter check is never inlined so it doesn't clutter the fast
+ /// path.
#[inline(always)]
fn exec<F>(&self, event_filter: EventFilter, f: F) -> TimingGuard<'_>
where
F: for<'a> FnOnce(&'a SelfProfiler) -> TimingGuard<'a>,
{
#[inline(never)]
+ #[cold]
fn cold_call<F>(profiler_ref: &SelfProfilerRef, f: F) -> TimingGuard<'_>
where
F: for<'a> FnOnce(&'a SelfProfiler) -> TimingGuard<'a>,
f(&**profiler)
}
- if unlikely!(self.event_filter_mask.contains(event_filter)) {
+ if self.event_filter_mask.contains(event_filter) {
cold_call(self, f)
} else {
TimingGuard::none()
/// Start profiling a verbose generic activity. Profiling continues until the
/// VerboseTimingGuard returned from this call is dropped. In addition to recording
/// a measureme event, "verbose" generic activities also print a timing entry to
- /// stdout if the compiler is invoked with -Ztime or -Ztime-passes.
+ /// stderr if the compiler is invoked with -Ztime-passes.
pub fn verbose_generic_activity<'a>(
&'a self,
event_label: &'static str,
VerboseTimingGuard::start(message, self.generic_activity(event_label))
}
- /// Start profiling a extra verbose generic activity. Profiling continues until the
- /// VerboseTimingGuard returned from this call is dropped. In addition to recording
- /// a measureme event, "extra verbose" generic activities also print a timing entry to
- /// stdout if the compiler is invoked with -Ztime-passes.
- pub fn extra_verbose_generic_activity<'a, A>(
+ /// Like `verbose_generic_activity`, but with an extra arg.
+ pub fn verbose_generic_activity_with_arg<'a, A>(
&'a self,
event_label: &'static str,
event_arg: A,
where
A: Borrow<str> + Into<String>,
{
- let message = if self.print_extra_verbose_generic_activities {
+ let message = if self.print_verbose_generic_activities {
Some(format!("{}({})", event_label, event_arg.borrow()))
} else {
None
})
}
+ /// Start profiling a generic activity, allowing costly arguments to be recorded. Profiling
+ /// continues until the `TimingGuard` returned from this call is dropped.
+ ///
+ /// If the arguments to a generic activity are cheap to create, use `generic_activity_with_arg`
+ /// or `generic_activity_with_args` for their simpler API. However, if they are costly or
+ /// require allocation in sufficiently hot contexts, then this allows for a closure to be called
+ /// only when arguments were asked to be recorded via `-Z self-profile-events=args`.
+ ///
+ /// In this case, the closure will be passed a `&mut EventArgRecorder`, to help with recording
+ /// one or many arguments within the generic activity being profiled, by calling its
+ /// `record_arg` method for example.
+ ///
+ /// This `EventArgRecorder` may implement more specific traits from other rustc crates, e.g. for
+ /// richer handling of rustc-specific argument types, while keeping this single entry-point API
+ /// for recording arguments.
+ ///
+ /// Note: recording at least one argument is *required* for the self-profiler to create the
+ /// `TimingGuard`. A panic will be triggered if that doesn't happen. This function exists
+ /// explicitly to record arguments, so it fails loudly when there are none to record.
+ ///
+ #[inline(always)]
+ pub fn generic_activity_with_arg_recorder<F>(
+ &self,
+ event_label: &'static str,
+ mut f: F,
+ ) -> TimingGuard<'_>
+ where
+ F: FnMut(&mut EventArgRecorder<'_>),
+ {
+ // Ensure this event will only be recorded when self-profiling is turned on.
+ self.exec(EventFilter::GENERIC_ACTIVITIES, |profiler| {
+ let builder = EventIdBuilder::new(&profiler.profiler);
+ let event_label = profiler.get_or_alloc_cached_string(event_label);
+
+ // Ensure the closure to create event arguments will only be called when argument
+ // recording is turned on.
+ let event_id = if profiler.event_filter_mask.contains(EventFilter::FUNCTION_ARGS) {
+ // Set up the builder and call the user-provided closure to record potentially
+ // costly event arguments.
+ let mut recorder = EventArgRecorder { profiler, args: SmallVec::new() };
+ f(&mut recorder);
+
+ // It is expected that the closure will record at least one argument. If that
+ // doesn't happen, it's a bug: we've been explicitly called in order to record
+ // arguments, so we fail loudly when there are none to record.
+ if recorder.args.is_empty() {
+ panic!(
+ "The closure passed to `generic_activity_with_arg_recorder` needs to \
+ record at least one argument"
+ );
+ }
+
+ builder.from_label_and_args(event_label, &recorder.args)
+ } else {
+ builder.from_label(event_label)
+ };
+ TimingGuard::start(profiler, profiler.generic_activity_event_kind, event_id)
+ })
+ }
+
+ /// Record the size of an artifact that the compiler produces
+ ///
+ /// `artifact_kind` is the class of artifact (e.g., query_cache, object_file, etc.)
+ /// `artifact_name` is an identifier to the specific artifact being stored (usually a filename)
+ #[inline(always)]
+ pub fn artifact_size<A>(&self, artifact_kind: &str, artifact_name: A, size: u64)
+ where
+ A: Borrow<str> + Into<String>,
+ {
+ drop(self.exec(EventFilter::ARTIFACT_SIZES, |profiler| {
+ let builder = EventIdBuilder::new(&profiler.profiler);
+ let event_label = profiler.get_or_alloc_cached_string(artifact_kind);
+ let event_arg = profiler.get_or_alloc_cached_string(artifact_name);
+ let event_id = builder.from_label_and_arg(event_label, event_arg);
+ let thread_id = get_thread_id();
+
+ profiler.profiler.record_integer_event(
+ profiler.artifact_size_event_kind,
+ event_id,
+ thread_id,
+ size,
+ );
+
+ TimingGuard::none()
+ }))
+ }
+
#[inline(always)]
pub fn generic_activity_with_args(
&self,
) {
drop(self.exec(event_filter, |profiler| {
let event_id = StringId::new_virtual(query_invocation_id.0);
- let thread_id = std::thread::current().id().as_u64().get() as u32;
+ let thread_id = get_thread_id();
profiler.profiler.record_instant_event(
event_kind(profiler),
}
}
+/// A helper for recording costly arguments to self-profiling events. Used with
+/// `SelfProfilerRef::generic_activity_with_arg_recorder`.
+pub struct EventArgRecorder<'p> {
+ /// The `SelfProfiler` used to intern the event arguments that users will ask to record.
+ profiler: &'p SelfProfiler,
+
+ /// The interned event arguments to be recorded in the generic activity event.
+ ///
+ /// The most common case, when actually recording event arguments, is to have one argument. Then
+ /// followed by recording two, in a couple places.
+ args: SmallVec<[StringId; 2]>,
+}
+
+impl EventArgRecorder<'_> {
+ /// Records a single argument within the current generic activity being profiled.
+ ///
+ /// Note: when self-profiling with costly event arguments, at least one argument
+ /// needs to be recorded. A panic will be triggered if that doesn't happen.
+ pub fn record_arg<A>(&mut self, event_arg: A)
+ where
+ A: Borrow<str> + Into<String>,
+ {
+ let event_arg = self.profiler.get_or_alloc_cached_string(event_arg);
+ self.args.push(event_arg);
+ }
+}
+
pub struct SelfProfiler {
profiler: Profiler,
event_filter_mask: EventFilter,
incremental_result_hashing_event_kind: StringId,
query_blocked_event_kind: StringId,
query_cache_hit_event_kind: StringId,
+ artifact_size_event_kind: StringId,
}
impl SelfProfiler {
pub fn new(
output_directory: &Path,
crate_name: Option<&str>,
- event_filters: &Option<Vec<String>>,
+ event_filters: Option<&[String]>,
+ counter_name: &str,
) -> Result<SelfProfiler, Box<dyn Error + Send + Sync>> {
fs::create_dir_all(output_directory)?;
let crate_name = crate_name.unwrap_or("unknown-crate");
- let filename = format!("{}-{}.rustc_profile", crate_name, process::id());
+ // HACK(eddyb) we need to pad the PID, strange as it may seem, as its
+ // length can behave as a source of entropy for heap addresses, when
+ // ASLR is disabled and the heap is otherwise determinic.
+ let pid: u32 = process::id();
+ let filename = format!("{}-{:07}.rustc_profile", crate_name, pid);
let path = output_directory.join(&filename);
- let profiler = Profiler::new(&path)?;
+ let profiler =
+ Profiler::with_counter(&path, measureme::counters::Counter::by_name(counter_name)?)?;
let query_event_kind = profiler.alloc_string("Query");
let generic_activity_event_kind = profiler.alloc_string("GenericActivity");
profiler.alloc_string("IncrementalResultHashing");
let query_blocked_event_kind = profiler.alloc_string("QueryBlocked");
let query_cache_hit_event_kind = profiler.alloc_string("QueryCacheHit");
+ let artifact_size_event_kind = profiler.alloc_string("ArtifactSize");
let mut event_filter_mask = EventFilter::empty();
- if let Some(ref event_filters) = *event_filters {
+ if let Some(event_filters) = event_filters {
let mut unknown_events = vec![];
for item in event_filters {
if let Some(&(_, mask)) =
incremental_result_hashing_event_kind,
query_blocked_event_kind,
query_cache_hit_event_kind,
+ artifact_size_event_kind,
})
}
event_kind: StringId,
event_id: EventId,
) -> TimingGuard<'a> {
- let thread_id = std::thread::current().id().as_u64().get() as u32;
+ let thread_id = get_thread_id();
let raw_profiler = &profiler.profiler;
let timing_guard =
raw_profiler.start_recording_interval_event(event_kind, event_id, thread_id);
fn drop(&mut self) {
if let Some((start_time, start_rss, ref message)) = self.start_and_message {
let end_rss = get_resident_set_size();
- print_time_passes_entry(&message[..], start_time.elapsed(), start_rss, end_rss);
+ let dur = start_time.elapsed();
+ print_time_passes_entry(&message, dur, start_rss, end_rss);
}
}
}
start_rss: Option<usize>,
end_rss: Option<usize>,
) {
+ // Print the pass if its duration is greater than 5 ms, or it changed the
+ // measured RSS.
+ let is_notable = || {
+ if dur.as_millis() > 5 {
+ return true;
+ }
+
+ if let (Some(start_rss), Some(end_rss)) = (start_rss, end_rss) {
+ let change_rss = end_rss.abs_diff(start_rss);
+ if change_rss > 0 {
+ return true;
+ }
+ }
+
+ false
+ };
+ if !is_notable() {
+ return;
+ }
+
let rss_to_mb = |rss| (rss as f64 / 1_000_000.0).round() as usize;
let rss_change_to_mb = |rss| (rss as f64 / 1_000_000.0).round() as i128;
format!("{:.3}", dur.as_secs_f64())
}
+fn get_thread_id() -> u32 {
+ std::thread::current().id().as_u64().get() as u32
+}
+
// Memory reporting
cfg_if! {
if #[cfg(windows)] {
}
}
}
+ } else if #[cfg(target_os = "macos")] {
+ pub fn get_resident_set_size() -> Option<usize> {
+ use libc::{c_int, c_void, getpid, proc_pidinfo, proc_taskinfo, PROC_PIDTASKINFO};
+ use std::mem;
+ const PROC_TASKINFO_SIZE: c_int = mem::size_of::<proc_taskinfo>() as c_int;
+
+ unsafe {
+ let mut info: proc_taskinfo = mem::zeroed();
+ let info_ptr = &mut info as *mut proc_taskinfo as *mut c_void;
+ let pid = getpid() as c_int;
+ let ret = proc_pidinfo(pid, PROC_PIDTASKINFO, 0, info_ptr, PROC_TASKINFO_SIZE);
+ if ret == PROC_TASKINFO_SIZE {
+ Some(info.pti_resident_size as usize)
+ } else {
+ None
+ }
+ }
+ }
} else if #[cfg(unix)] {
pub fn get_resident_set_size() -> Option<usize> {
let field = 1;