]> git.proxmox.com Git - rustc.git/blobdiff - compiler/rustc_data_structures/src/profiling.rs
New upstream version 1.66.0+dfsg1
[rustc.git] / compiler / rustc_data_structures / src / profiling.rs
index ef101c56ab578716525fb042b72eb0b056988728..ba1960805d84bf0301539f5e50363a8859db4c9d 100644 (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 smallvec::SmallVec;
 
 bitflags::bitflags! {
     struct EventFilter: u32 {
@@ -110,12 +111,14 @@ bitflags::bitflags! {
         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;
     }
@@ -136,6 +139,7 @@ const EVENT_FILTERS_BY_NAME: &[(&str, EventFilter)] = &[
     ("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.
@@ -154,43 +158,35 @@ pub struct SelfProfilerRef {
     // 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>,
@@ -199,7 +195,7 @@ impl SelfProfilerRef {
             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()
@@ -209,7 +205,7 @@ impl SelfProfilerRef {
     /// 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,
@@ -220,11 +216,8 @@ impl SelfProfilerRef {
         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,
@@ -232,7 +225,7 @@ impl SelfProfilerRef {
     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
@@ -285,6 +278,93 @@ impl SelfProfilerRef {
         })
     }
 
+    /// 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,
@@ -372,7 +452,7 @@ impl SelfProfilerRef {
     ) {
         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),
@@ -413,6 +493,33 @@ impl SelfProfilerRef {
     }
 }
 
+/// 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,
@@ -425,20 +532,27 @@ pub struct SelfProfiler {
     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");
@@ -447,10 +561,11 @@ impl SelfProfiler {
             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)) =
@@ -491,6 +606,7 @@ impl SelfProfiler {
             incremental_result_hashing_event_kind,
             query_blocked_event_kind,
             query_cache_hit_event_kind,
+            artifact_size_event_kind,
         })
     }
 
@@ -561,7 +677,7 @@ impl<'a> TimingGuard<'a> {
         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);
@@ -616,7 +732,8 @@ impl Drop for VerboseTimingGuard<'_> {
     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);
         }
     }
 }
@@ -627,6 +744,26 @@ pub fn print_time_passes_entry(
     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;
 
@@ -655,6 +792,10 @@ pub fn duration_to_secs_str(dur: std::time::Duration) -> String {
     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)] {
@@ -675,6 +816,24 @@ cfg_if! {
                 }
             }
         }
+    } 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;