aboutsummaryrefslogtreecommitdiff
path: root/crates/profile/src
diff options
context:
space:
mode:
Diffstat (limited to 'crates/profile/src')
-rw-r--r--crates/profile/src/google_cpu_profiler.rs19
-rw-r--r--crates/profile/src/hprof.rs107
-rw-r--r--crates/profile/src/lib.rs39
3 files changed, 135 insertions, 30 deletions
diff --git a/crates/profile/src/google_cpu_profiler.rs b/crates/profile/src/google_cpu_profiler.rs
index db865c65b..cae6caeaa 100644
--- a/crates/profile/src/google_cpu_profiler.rs
+++ b/crates/profile/src/google_cpu_profiler.rs
@@ -14,26 +14,31 @@ extern "C" {
14 fn ProfilerStop(); 14 fn ProfilerStop();
15} 15}
16 16
17static PROFILER_STATE: AtomicUsize = AtomicUsize::new(OFF);
18const OFF: usize = 0; 17const OFF: usize = 0;
19const ON: usize = 1; 18const ON: usize = 1;
20const PENDING: usize = 2; 19const PENDING: usize = 2;
21 20
22pub fn start(path: &Path) { 21fn transition(current: usize, new: usize) -> bool {
23 if PROFILER_STATE.compare_and_swap(OFF, PENDING, Ordering::SeqCst) != OFF { 22 static STATE: AtomicUsize = AtomicUsize::new(OFF);
23
24 STATE.compare_exchange(current, new, Ordering::SeqCst, Ordering::SeqCst).is_ok()
25}
26
27pub(crate) fn start(path: &Path) {
28 if !transition(OFF, PENDING) {
24 panic!("profiler already started"); 29 panic!("profiler already started");
25 } 30 }
26 let path = CString::new(path.display().to_string()).unwrap(); 31 let path = CString::new(path.display().to_string()).unwrap();
27 if unsafe { ProfilerStart(path.as_ptr()) } == 0 { 32 if unsafe { ProfilerStart(path.as_ptr()) } == 0 {
28 panic!("profiler failed to start") 33 panic!("profiler failed to start")
29 } 34 }
30 assert!(PROFILER_STATE.compare_and_swap(PENDING, ON, Ordering::SeqCst) == PENDING); 35 assert!(transition(PENDING, ON));
31} 36}
32 37
33pub fn stop() { 38pub(crate) fn stop() {
34 if PROFILER_STATE.compare_and_swap(ON, PENDING, Ordering::SeqCst) != ON { 39 if !transition(ON, PENDING) {
35 panic!("profiler is not started") 40 panic!("profiler is not started")
36 } 41 }
37 unsafe { ProfilerStop() }; 42 unsafe { ProfilerStop() };
38 assert!(PROFILER_STATE.compare_and_swap(PENDING, OFF, Ordering::SeqCst) == PENDING); 43 assert!(transition(PENDING, OFF));
39} 44}
diff --git a/crates/profile/src/hprof.rs b/crates/profile/src/hprof.rs
index 29d2ed518..5fdb37206 100644
--- a/crates/profile/src/hprof.rs
+++ b/crates/profile/src/hprof.rs
@@ -1,5 +1,4 @@
1//! Simple hierarchical profiler 1//! Simple hierarchical profiler
2use once_cell::sync::Lazy;
3use std::{ 2use std::{
4 cell::RefCell, 3 cell::RefCell,
5 collections::{BTreeMap, HashSet}, 4 collections::{BTreeMap, HashSet},
@@ -12,6 +11,8 @@ use std::{
12 time::{Duration, Instant}, 11 time::{Duration, Instant},
13}; 12};
14 13
14use once_cell::sync::Lazy;
15
15use crate::tree::{Idx, Tree}; 16use crate::tree::{Idx, Tree};
16 17
17/// Filtering syntax 18/// Filtering syntax
@@ -56,18 +57,32 @@ type Label = &'static str;
56/// 0ms - profile 57/// 0ms - profile
57/// 0ms - profile2 58/// 0ms - profile2
58/// ``` 59/// ```
60#[inline]
59pub fn span(label: Label) -> ProfileSpan { 61pub fn span(label: Label) -> ProfileSpan {
60 assert!(!label.is_empty()); 62 debug_assert!(!label.is_empty());
61 63
62 if PROFILING_ENABLED.load(Ordering::Relaxed) 64 let enabled = PROFILING_ENABLED.load(Ordering::Relaxed);
63 && PROFILE_STACK.with(|stack| stack.borrow_mut().push(label)) 65 if enabled && with_profile_stack(|stack| stack.push(label)) {
64 {
65 ProfileSpan(Some(ProfilerImpl { label, detail: None })) 66 ProfileSpan(Some(ProfilerImpl { label, detail: None }))
66 } else { 67 } else {
67 ProfileSpan(None) 68 ProfileSpan(None)
68 } 69 }
69} 70}
70 71
72#[inline]
73pub fn heartbeat_span() -> HeartbeatSpan {
74 let enabled = PROFILING_ENABLED.load(Ordering::Relaxed);
75 HeartbeatSpan::new(enabled)
76}
77
78#[inline]
79pub fn heartbeat() {
80 let enabled = PROFILING_ENABLED.load(Ordering::Relaxed);
81 if enabled {
82 with_profile_stack(|it| it.heartbeat(1));
83 }
84}
85
71pub struct ProfileSpan(Option<ProfilerImpl>); 86pub struct ProfileSpan(Option<ProfilerImpl>);
72 87
73struct ProfilerImpl { 88struct ProfilerImpl {
@@ -85,20 +100,48 @@ impl ProfileSpan {
85} 100}
86 101
87impl Drop for ProfilerImpl { 102impl Drop for ProfilerImpl {
103 #[inline]
104 fn drop(&mut self) {
105 with_profile_stack(|it| it.pop(self.label, self.detail.take()));
106 }
107}
108
109pub struct HeartbeatSpan {
110 enabled: bool,
111}
112
113impl HeartbeatSpan {
114 #[inline]
115 pub fn new(enabled: bool) -> Self {
116 if enabled {
117 with_profile_stack(|it| it.heartbeats(true))
118 }
119 Self { enabled }
120 }
121}
122
123impl Drop for HeartbeatSpan {
88 fn drop(&mut self) { 124 fn drop(&mut self) {
89 PROFILE_STACK.with(|it| it.borrow_mut().pop(self.label, self.detail.take())); 125 if self.enabled {
126 with_profile_stack(|it| it.heartbeats(false))
127 }
90 } 128 }
91} 129}
92 130
93static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false); 131static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false);
94static FILTER: Lazy<RwLock<Filter>> = Lazy::new(Default::default); 132static FILTER: Lazy<RwLock<Filter>> = Lazy::new(Default::default);
95thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new())); 133
134fn with_profile_stack<T>(f: impl FnOnce(&mut ProfileStack) -> T) -> T {
135 thread_local!(static STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new()));
136 STACK.with(|it| f(&mut *it.borrow_mut()))
137}
96 138
97#[derive(Default, Clone, Debug)] 139#[derive(Default, Clone, Debug)]
98struct Filter { 140struct Filter {
99 depth: usize, 141 depth: usize,
100 allowed: HashSet<String>, 142 allowed: HashSet<String>,
101 longer_than: Duration, 143 longer_than: Duration,
144 heartbeat_longer_than: Duration,
102 version: usize, 145 version: usize,
103} 146}
104 147
@@ -115,6 +158,7 @@ impl Filter {
115 } else { 158 } else {
116 Duration::new(0, 0) 159 Duration::new(0, 0)
117 }; 160 };
161 let heartbeat_longer_than = longer_than;
118 162
119 let depth = if let Some(idx) = spec.rfind('@') { 163 let depth = if let Some(idx) = spec.rfind('@') {
120 let depth: usize = spec[idx + 1..].parse().expect("invalid profile depth"); 164 let depth: usize = spec[idx + 1..].parse().expect("invalid profile depth");
@@ -125,7 +169,7 @@ impl Filter {
125 }; 169 };
126 let allowed = 170 let allowed =
127 if spec == "*" { HashSet::new() } else { spec.split('|').map(String::from).collect() }; 171 if spec == "*" { HashSet::new() } else { spec.split('|').map(String::from).collect() };
128 Filter { depth, allowed, longer_than, version: 0 } 172 Filter { depth, allowed, longer_than, heartbeat_longer_than, version: 0 }
129 } 173 }
130 174
131 fn install(mut self) { 175 fn install(mut self) {
@@ -137,9 +181,15 @@ impl Filter {
137} 181}
138 182
139struct ProfileStack { 183struct ProfileStack {
140 starts: Vec<Instant>, 184 frames: Vec<Frame>,
141 filter: Filter, 185 filter: Filter,
142 messages: Tree<Message>, 186 messages: Tree<Message>,
187 heartbeats: bool,
188}
189
190struct Frame {
191 t: Instant,
192 heartbeats: u32,
143} 193}
144 194
145#[derive(Default)] 195#[derive(Default)]
@@ -151,35 +201,49 @@ struct Message {
151 201
152impl ProfileStack { 202impl ProfileStack {
153 fn new() -> ProfileStack { 203 fn new() -> ProfileStack {
154 ProfileStack { starts: Vec::new(), messages: Tree::default(), filter: Default::default() } 204 ProfileStack {
205 frames: Vec::new(),
206 messages: Tree::default(),
207 filter: Default::default(),
208 heartbeats: false,
209 }
155 } 210 }
156 211
157 fn push(&mut self, label: Label) -> bool { 212 fn push(&mut self, label: Label) -> bool {
158 if self.starts.is_empty() { 213 if self.frames.is_empty() {
159 if let Ok(f) = FILTER.try_read() { 214 if let Ok(f) = FILTER.try_read() {
160 if f.version > self.filter.version { 215 if f.version > self.filter.version {
161 self.filter = f.clone(); 216 self.filter = f.clone();
162 } 217 }
163 }; 218 };
164 } 219 }
165 if self.starts.len() > self.filter.depth { 220 if self.frames.len() > self.filter.depth {
166 return false; 221 return false;
167 } 222 }
168 let allowed = &self.filter.allowed; 223 let allowed = &self.filter.allowed;
169 if self.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) { 224 if self.frames.is_empty() && !allowed.is_empty() && !allowed.contains(label) {
170 return false; 225 return false;
171 } 226 }
172 227
173 self.starts.push(Instant::now()); 228 self.frames.push(Frame { t: Instant::now(), heartbeats: 0 });
174 self.messages.start(); 229 self.messages.start();
175 true 230 true
176 } 231 }
177 232
178 fn pop(&mut self, label: Label, detail: Option<String>) { 233 fn pop(&mut self, label: Label, detail: Option<String>) {
179 let start = self.starts.pop().unwrap(); 234 let frame = self.frames.pop().unwrap();
180 let duration = start.elapsed(); 235 let duration = frame.t.elapsed();
236
237 if self.heartbeats {
238 self.heartbeat(frame.heartbeats);
239 let avg_span = duration / (frame.heartbeats + 1);
240 if avg_span > self.filter.heartbeat_longer_than {
241 eprintln!("Too few heartbeats {} ({}/{:?})?", label, frame.heartbeats, duration)
242 }
243 }
244
181 self.messages.finish(Message { duration, label, detail }); 245 self.messages.finish(Message { duration, label, detail });
182 if self.starts.is_empty() { 246 if self.frames.is_empty() {
183 let longer_than = self.filter.longer_than; 247 let longer_than = self.filter.longer_than;
184 // Convert to millis for comparison to avoid problems with rounding 248 // Convert to millis for comparison to avoid problems with rounding
185 // (otherwise we could print `0ms` despite user's `>0` filter when 249 // (otherwise we could print `0ms` despite user's `>0` filter when
@@ -192,6 +256,15 @@ impl ProfileStack {
192 self.messages.clear(); 256 self.messages.clear();
193 } 257 }
194 } 258 }
259
260 fn heartbeats(&mut self, yes: bool) {
261 self.heartbeats = yes;
262 }
263 fn heartbeat(&mut self, n: u32) {
264 if let Some(frame) = self.frames.last_mut() {
265 frame.heartbeats += n;
266 }
267 }
195} 268}
196 269
197fn print( 270fn print(
diff --git a/crates/profile/src/lib.rs b/crates/profile/src/lib.rs
index 79dba47d5..a31fb8f43 100644
--- a/crates/profile/src/lib.rs
+++ b/crates/profile/src/lib.rs
@@ -10,7 +10,7 @@ mod tree;
10use std::cell::RefCell; 10use std::cell::RefCell;
11 11
12pub use crate::{ 12pub use crate::{
13 hprof::{init, init_from, span}, 13 hprof::{heartbeat, heartbeat_span, init, init_from, span},
14 memory_usage::{Bytes, MemoryUsage}, 14 memory_usage::{Bytes, MemoryUsage},
15 stop_watch::{StopWatch, StopWatchSpan}, 15 stop_watch::{StopWatch, StopWatchSpan},
16}; 16};
@@ -52,7 +52,7 @@ impl Drop for Scope {
52/// Usage: 52/// Usage:
53/// 1. Install gpref_tools (https://github.com/gperftools/gperftools), probably packaged with your Linux distro. 53/// 1. Install gpref_tools (https://github.com/gperftools/gperftools), probably packaged with your Linux distro.
54/// 2. Build with `cpu_profiler` feature. 54/// 2. Build with `cpu_profiler` feature.
55/// 3. Tun the code, the *raw* output would be in the `./out.profile` file. 55/// 3. Run the code, the *raw* output would be in the `./out.profile` file.
56/// 4. Install pprof for visualization (https://github.com/google/pprof). 56/// 4. Install pprof for visualization (https://github.com/google/pprof).
57/// 5. Bump sampling frequency to once per ms: `export CPUPROFILE_FREQUENCY=1000` 57/// 5. Bump sampling frequency to once per ms: `export CPUPROFILE_FREQUENCY=1000`
58/// 6. Use something like `pprof -svg target/release/rust-analyzer ./out.profile` to see the results. 58/// 6. Use something like `pprof -svg target/release/rust-analyzer ./out.profile` to see the results.
@@ -60,8 +60,17 @@ impl Drop for Scope {
60/// For example, here's how I run profiling on NixOS: 60/// For example, here's how I run profiling on NixOS:
61/// 61///
62/// ```bash 62/// ```bash
63/// $ nix-shell -p gperftools --run \ 63/// $ bat -p shell.nix
64/// 'cargo run --release -p rust-analyzer -- parse < ~/projects/rustbench/parser.rs > /dev/null' 64/// with import <nixpkgs> {};
65/// mkShell {
66/// buildInputs = [ gperftools ];
67/// shellHook = ''
68/// export LD_LIBRARY_PATH="${gperftools}/lib:"
69/// '';
70/// }
71/// $ set -x CPUPROFILE_FREQUENCY 1000
72/// $ nix-shell --run 'cargo test --release --package rust-analyzer --lib -- benchmarks::benchmark_integrated_highlighting --exact --nocapture'
73/// $ pprof -svg target/release/deps/rust_analyzer-8739592dc93d63cb crates/rust-analyzer/out.profile > profile.svg
65/// ``` 74/// ```
66/// 75///
67/// See this diff for how to profile completions: 76/// See this diff for how to profile completions:
@@ -81,7 +90,9 @@ pub fn cpu_span() -> CpuSpan {
81 90
82 #[cfg(not(feature = "cpu_profiler"))] 91 #[cfg(not(feature = "cpu_profiler"))]
83 { 92 {
84 eprintln!("cpu_profiler feature is disabled") 93 eprintln!(
94 r#"cpu profiling is disabled, uncomment `default = [ "cpu_profiler" ]` in Cargo.toml to enable."#
95 )
85 } 96 }
86 97
87 CpuSpan { _private: () } 98 CpuSpan { _private: () }
@@ -91,7 +102,23 @@ impl Drop for CpuSpan {
91 fn drop(&mut self) { 102 fn drop(&mut self) {
92 #[cfg(feature = "cpu_profiler")] 103 #[cfg(feature = "cpu_profiler")]
93 { 104 {
94 google_cpu_profiler::stop() 105 google_cpu_profiler::stop();
106 let profile_data = std::env::current_dir().unwrap().join("out.profile");
107 eprintln!("Profile data saved to:\n\n {}\n", profile_data.display());
108 let mut cmd = std::process::Command::new("pprof");
109 cmd.arg("-svg").arg(std::env::current_exe().unwrap()).arg(&profile_data);
110 let out = cmd.output();
111
112 match out {
113 Ok(out) if out.status.success() => {
114 let svg = profile_data.with_extension("svg");
115 std::fs::write(&svg, &out.stdout).unwrap();
116 eprintln!("Profile rendered to:\n\n {}\n", svg.display());
117 }
118 _ => {
119 eprintln!("Failed to run:\n\n {:?}\n", cmd);
120 }
121 }
95 } 122 }
96 } 123 }
97} 124}