From f6aa64b7b0e2a39708a1baf631f46cf02025cbe9 Mon Sep 17 00:00:00 2001 From: Michael Woerister Date: Thu, 24 Oct 2019 17:13:38 +0200 Subject: [PATCH 1/3] self-profiling: Remove unused methods from profiler. --- src/librustc/util/profiling.rs | 48 ---------------------------------- 1 file changed, 48 deletions(-) diff --git a/src/librustc/util/profiling.rs b/src/librustc/util/profiling.rs index bd02e7f5a14a..0ca0ac82533b 100644 --- a/src/librustc/util/profiling.rs +++ b/src/librustc/util/profiling.rs @@ -131,32 +131,6 @@ impl SelfProfilerRef { }) } - /// Start profiling a generic activity. Profiling continues until - /// `generic_activity_end` is called. The RAII-based `generic_activity` - /// usually is the better alternative. - #[inline(always)] - pub fn generic_activity_start(&self, event_id: &str) { - self.non_guard_generic_event( - |profiler| profiler.generic_activity_event_kind, - |profiler| profiler.profiler.alloc_string(event_id), - EventFilter::GENERIC_ACTIVITIES, - TimestampKind::Start, - ); - } - - /// End profiling a generic activity that was started with - /// `generic_activity_start`. The RAII-based `generic_activity` usually is - /// the better alternative. - #[inline(always)] - pub fn generic_activity_end(&self, event_id: &str) { - self.non_guard_generic_event( - |profiler| profiler.generic_activity_event_kind, - |profiler| profiler.profiler.alloc_string(event_id), - EventFilter::GENERIC_ACTIVITIES, - TimestampKind::End, - ); - } - /// Start profiling a query provider. Profiling continues until the /// TimingGuard returned from this call is dropped. #[inline(always)] @@ -238,28 +212,6 @@ impl SelfProfilerRef { TimingGuard::none() })); } - - #[inline(always)] - fn non_guard_generic_event StringId>( - &self, - event_kind: fn(&SelfProfiler) -> StringId, - event_id: F, - event_filter: EventFilter, - timestamp_kind: TimestampKind - ) { - drop(self.exec(event_filter, |profiler| { - let thread_id = thread_id_to_u64(std::thread::current().id()); - - profiler.profiler.record_event( - event_kind(profiler), - event_id(profiler), - thread_id, - timestamp_kind, - ); - - TimingGuard::none() - })); - } } pub struct SelfProfiler { From ee1173a8ffaf51335a4eb7198cd0ce7f508abfd0 Mon Sep 17 00:00:00 2001 From: Michael Woerister Date: Thu, 24 Oct 2019 17:14:38 +0200 Subject: [PATCH 2/3] self-profiling: Update measureme to 0.4.0 and use new RAII-based API. --- Cargo.lock | 4 ++-- src/librustc/Cargo.toml | 2 +- src/librustc/util/profiling.rs | 40 +++++++++------------------------- 3 files changed, 13 insertions(+), 33 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index efcbd7b6794f..8e0db18e1577 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1954,9 +1954,9 @@ dependencies = [ [[package]] name = "measureme" -version = "0.3.0" +version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d09de7dafa3aa334bc806447c7e4de69419723312f4b88b80b561dea66601ce8" +checksum = "cd21b0e6e1af976b269ce062038fe5e1b9ca2f817ab7a3af09ec4210aebf0d30" dependencies = [ "byteorder", "memmap", diff --git a/src/librustc/Cargo.toml b/src/librustc/Cargo.toml index 93274ef0c927..38631224fd35 100644 --- a/src/librustc/Cargo.toml +++ b/src/librustc/Cargo.toml @@ -37,4 +37,4 @@ byteorder = { version = "1.3" } chalk-engine = { version = "0.9.0", default-features=false } rustc_fs_util = { path = "../librustc_fs_util" } smallvec = { version = "0.6.8", features = ["union", "may_dangle"] } -measureme = "0.3" +measureme = "0.4" diff --git a/src/librustc/util/profiling.rs b/src/librustc/util/profiling.rs index 0ca0ac82533b..08cd68655aa5 100644 --- a/src/librustc/util/profiling.rs +++ b/src/librustc/util/profiling.rs @@ -14,9 +14,12 @@ use measureme::{StringId, TimestampKind}; /// MmapSerializatioSink is faster on macOS and Linux /// but FileSerializationSink is faster on Windows #[cfg(not(windows))] -type Profiler = measureme::Profiler; +type SerializationSink = measureme::MmapSerializationSink; #[cfg(windows)] -type Profiler = measureme::Profiler; +type SerializationSink = measureme::FileSerializationSink; + +type Profiler = measureme::Profiler; + #[derive(Clone, Copy, Debug, PartialEq, Eq, Ord, PartialOrd)] pub enum ProfileCategory { @@ -298,14 +301,7 @@ impl SelfProfiler { } #[must_use] -pub struct TimingGuard<'a>(Option>); - -struct TimingGuardInternal<'a> { - raw_profiler: &'a Profiler, - event_id: StringId, - event_kind: StringId, - thread_id: u64, -} +pub struct TimingGuard<'a>(Option>); impl<'a> TimingGuard<'a> { #[inline] @@ -316,14 +312,10 @@ impl<'a> TimingGuard<'a> { ) -> TimingGuard<'a> { let thread_id = thread_id_to_u64(std::thread::current().id()); let raw_profiler = &profiler.profiler; - raw_profiler.record_event(event_kind, event_id, thread_id, TimestampKind::Start); - - TimingGuard(Some(TimingGuardInternal { - raw_profiler, - event_kind, - event_id, - thread_id, - })) + let timing_guard = raw_profiler.start_recording_interval_event(event_kind, + event_id, + thread_id); + TimingGuard(Some(timing_guard)) } #[inline] @@ -331,15 +323,3 @@ impl<'a> TimingGuard<'a> { TimingGuard(None) } } - -impl<'a> Drop for TimingGuardInternal<'a> { - #[inline] - fn drop(&mut self) { - self.raw_profiler.record_event( - self.event_kind, - self.event_id, - self.thread_id, - TimestampKind::End - ); - } -} From 9c083068e31e8eb4d4f1d3f649354408d866574c Mon Sep 17 00:00:00 2001 From: Michael Woerister Date: Thu, 24 Oct 2019 17:37:48 +0200 Subject: [PATCH 3/3] self-profiling: Switch query-blocking measurements to RAII-style API. --- src/librustc/ty/query/plumbing.rs | 14 ++++++++++++-- src/librustc/util/profiling.rs | 26 +++++++------------------- 2 files changed, 19 insertions(+), 21 deletions(-) diff --git a/src/librustc/ty/query/plumbing.rs b/src/librustc/ty/query/plumbing.rs index 41b4883793b5..538154b035ac 100644 --- a/src/librustc/ty/query/plumbing.rs +++ b/src/librustc/ty/query/plumbing.rs @@ -90,6 +90,10 @@ impl<'a, 'tcx, Q: QueryDescription<'tcx>> JobOwner<'a, 'tcx, Q> { } return TryGetJob::JobCompleted(result); } + + #[cfg(parallel_compiler)] + let query_blocked_prof_timer; + let job = match lock.active.entry((*key).clone()) { Entry::Occupied(entry) => { match *entry.get() { @@ -98,7 +102,9 @@ impl<'a, 'tcx, Q: QueryDescription<'tcx>> JobOwner<'a, 'tcx, Q> { // in another thread has completed. Record how long we wait in the // self-profiler. #[cfg(parallel_compiler)] - tcx.prof.query_blocked_start(Q::NAME); + { + query_blocked_prof_timer = tcx.prof.query_blocked(Q::NAME); + } job.clone() }, @@ -140,7 +146,11 @@ impl<'a, 'tcx, Q: QueryDescription<'tcx>> JobOwner<'a, 'tcx, Q> { #[cfg(parallel_compiler)] { let result = job.r#await(tcx, span); - tcx.prof.query_blocked_end(Q::NAME); + + // This `drop()` is not strictly necessary as the binding + // would go out of scope anyway. But it's good to have an + // explicit marker of how far the measurement goes. + drop(query_blocked_prof_timer); if let Err(cycle) = result { return TryGetJob::Cycle(Q::handle_cycle_error(tcx, cycle)); diff --git a/src/librustc/util/profiling.rs b/src/librustc/util/profiling.rs index 08cd68655aa5..5a1b7f3aa4cb 100644 --- a/src/librustc/util/profiling.rs +++ b/src/librustc/util/profiling.rs @@ -156,26 +156,14 @@ impl SelfProfilerRef { } /// Start profiling a query being blocked on a concurrent execution. - /// Profiling continues until `query_blocked_end` is called. + /// Profiling continues until the TimingGuard returned from this call is + /// dropped. #[inline(always)] - pub fn query_blocked_start(&self, query_name: QueryName) { - self.non_guard_query_event( - |profiler| profiler.query_blocked_event_kind, - query_name, - EventFilter::QUERY_BLOCKED, - TimestampKind::Start, - ); - } - - /// End profiling a query being blocked on a concurrent execution. - #[inline(always)] - pub fn query_blocked_end(&self, query_name: QueryName) { - self.non_guard_query_event( - |profiler| profiler.query_blocked_event_kind, - query_name, - EventFilter::QUERY_BLOCKED, - TimestampKind::End, - ); + pub fn query_blocked(&self, query_name: QueryName) -> TimingGuard<'_> { + self.exec(EventFilter::QUERY_BLOCKED, |profiler| { + let event_id = SelfProfiler::get_query_name_string_id(query_name); + TimingGuard::start(profiler, profiler.query_blocked_event_kind, event_id) + }) } /// Start profiling how long it takes to load a query result from the