aboutsummaryrefslogtreecommitdiff
path: root/crates/ra_prof
diff options
context:
space:
mode:
Diffstat (limited to 'crates/ra_prof')
-rw-r--r--crates/ra_prof/src/lib.rs57
1 files changed, 38 insertions, 19 deletions
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
index 6853a4794..9e167db96 100644
--- a/crates/ra_prof/src/lib.rs
+++ b/crates/ra_prof/src/lib.rs
@@ -88,7 +88,7 @@ pub type Label = &'static str;
88pub fn profile(label: Label) -> Profiler { 88pub fn profile(label: Label) -> Profiler {
89 assert!(!label.is_empty()); 89 assert!(!label.is_empty());
90 if !PROFILING_ENABLED.load(Ordering::Relaxed) { 90 if !PROFILING_ENABLED.load(Ordering::Relaxed) {
91 return Profiler { label: None }; 91 return Profiler { label: None, detail: None };
92 } 92 }
93 93
94 PROFILE_STACK.with(|stack| { 94 PROFILE_STACK.with(|stack| {
@@ -101,15 +101,15 @@ pub fn profile(label: Label) -> Profiler {
101 }; 101 };
102 } 102 }
103 if stack.starts.len() > stack.filter_data.depth { 103 if stack.starts.len() > stack.filter_data.depth {
104 return Profiler { label: None }; 104 return Profiler { label: None, detail: None };
105 } 105 }
106 let allowed = &stack.filter_data.allowed; 106 let allowed = &stack.filter_data.allowed;
107 if stack.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) { 107 if stack.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) {
108 return Profiler { label: None }; 108 return Profiler { label: None, detail: None };
109 } 109 }
110 110
111 stack.starts.push(Instant::now()); 111 stack.starts.push(Instant::now());
112 Profiler { label: Some(label) } 112 Profiler { label: Some(label), detail: None }
113 }) 113 })
114} 114}
115 115
@@ -130,6 +130,16 @@ pub fn print_time(label: Label) -> impl Drop {
130 130
131pub struct Profiler { 131pub struct Profiler {
132 label: Option<Label>, 132 label: Option<Label>,
133 detail: Option<String>,
134}
135
136impl Profiler {
137 pub fn detail(mut self, detail: impl FnOnce() -> String) -> Profiler {
138 if self.label.is_some() {
139 self.detail = Some(detail())
140 }
141 self
142 }
133} 143}
134 144
135pub struct Filter { 145pub struct Filter {
@@ -183,6 +193,7 @@ struct Message {
183 level: usize, 193 level: usize,
184 duration: Duration, 194 duration: Duration,
185 label: Label, 195 label: Label,
196 detail: Option<String>,
186} 197}
187 198
188impl ProfileStack { 199impl ProfileStack {
@@ -208,13 +219,13 @@ thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(Profile
208impl Drop for Profiler { 219impl Drop for Profiler {
209 fn drop(&mut self) { 220 fn drop(&mut self) {
210 match self { 221 match self {
211 Profiler { label: Some(label) } => { 222 Profiler { label: Some(label), detail } => {
212 PROFILE_STACK.with(|stack| { 223 PROFILE_STACK.with(|stack| {
213 let mut stack = stack.borrow_mut(); 224 let mut stack = stack.borrow_mut();
214 let start = stack.starts.pop().unwrap(); 225 let start = stack.starts.pop().unwrap();
215 let duration = start.elapsed(); 226 let duration = start.elapsed();
216 let level = stack.starts.len(); 227 let level = stack.starts.len();
217 stack.messages.push(Message { level, duration, label }); 228 stack.messages.push(Message { level, duration, label, detail: detail.take() });
218 if level == 0 { 229 if level == 0 {
219 let stdout = stderr(); 230 let stdout = stderr();
220 let longer_than = stack.filter_data.longer_than; 231 let longer_than = stack.filter_data.longer_than;
@@ -228,7 +239,7 @@ impl Drop for Profiler {
228 } 239 }
229 }); 240 });
230 } 241 }
231 Profiler { label: None } => (), 242 Profiler { label: None, .. } => (),
232 } 243 }
233 } 244 }
234} 245}
@@ -251,8 +262,16 @@ fn print_for_idx(
251) { 262) {
252 let current = &msgs[current_idx]; 263 let current = &msgs[current_idx];
253 let current_indent = " ".repeat(current.level); 264 let current_indent = " ".repeat(current.level);
254 writeln!(out, "{}{:5}ms - {}", current_indent, current.duration.as_millis(), current.label) 265 let detail = current.detail.as_ref().map(|it| format!(" @ {}", it)).unwrap_or_default();
255 .expect("printing profiling info"); 266 writeln!(
267 out,
268 "{}{:5}ms - {}{}",
269 current_indent,
270 current.duration.as_millis(),
271 current.label,
272 detail,
273 )
274 .expect("printing profiling info");
256 275
257 let longer_than_millis = longer_than.as_millis(); 276 let longer_than_millis = longer_than.as_millis();
258 let children_indices = &children_map[current_idx]; 277 let children_indices = &children_map[current_idx];
@@ -417,9 +436,9 @@ mod tests {
417 fn test_longer_than() { 436 fn test_longer_than() {
418 let mut result = vec![]; 437 let mut result = vec![];
419 let msgs = vec![ 438 let msgs = vec![
420 Message { level: 1, duration: Duration::from_nanos(3), label: "bar" }, 439 Message { level: 1, duration: Duration::from_nanos(3), label: "bar", detail: None },
421 Message { level: 1, duration: Duration::from_nanos(2), label: "bar" }, 440 Message { level: 1, duration: Duration::from_nanos(2), label: "bar", detail: None },
422 Message { level: 0, duration: Duration::from_millis(1), label: "foo" }, 441 Message { level: 0, duration: Duration::from_millis(1), label: "foo", detail: None },
423 ]; 442 ];
424 print(&msgs, Duration::from_millis(0), &mut result); 443 print(&msgs, Duration::from_millis(0), &mut result);
425 // The calls to `bar` are so short that they'll be rounded to 0ms and should get collapsed 444 // The calls to `bar` are so short that they'll be rounded to 0ms and should get collapsed
@@ -434,8 +453,8 @@ mod tests {
434 fn test_unaccounted_for_topmost() { 453 fn test_unaccounted_for_topmost() {
435 let mut result = vec![]; 454 let mut result = vec![];
436 let msgs = vec![ 455 let msgs = vec![
437 Message { level: 1, duration: Duration::from_millis(2), label: "bar" }, 456 Message { level: 1, duration: Duration::from_millis(2), label: "bar", detail: None },
438 Message { level: 0, duration: Duration::from_millis(5), label: "foo" }, 457 Message { level: 0, duration: Duration::from_millis(5), label: "foo", detail: None },
439 ]; 458 ];
440 print(&msgs, Duration::from_millis(0), &mut result); 459 print(&msgs, Duration::from_millis(0), &mut result);
441 assert_eq!( 460 assert_eq!(
@@ -453,11 +472,11 @@ mod tests {
453 fn test_unaccounted_for_multiple_levels() { 472 fn test_unaccounted_for_multiple_levels() {
454 let mut result = vec![]; 473 let mut result = vec![];
455 let msgs = vec![ 474 let msgs = vec![
456 Message { level: 2, duration: Duration::from_millis(3), label: "baz" }, 475 Message { level: 2, duration: Duration::from_millis(3), label: "baz", detail: None },
457 Message { level: 1, duration: Duration::from_millis(5), label: "bar" }, 476 Message { level: 1, duration: Duration::from_millis(5), label: "bar", detail: None },
458 Message { level: 2, duration: Duration::from_millis(2), label: "baz" }, 477 Message { level: 2, duration: Duration::from_millis(2), label: "baz", detail: None },
459 Message { level: 1, duration: Duration::from_millis(4), label: "bar" }, 478 Message { level: 1, duration: Duration::from_millis(4), label: "bar", detail: None },
460 Message { level: 0, duration: Duration::from_millis(9), label: "foo" }, 479 Message { level: 0, duration: Duration::from_millis(9), label: "foo", detail: None },
461 ]; 480 ];
462 print(&msgs, Duration::from_millis(0), &mut result); 481 print(&msgs, Duration::from_millis(0), &mut result);
463 assert_eq!( 482 assert_eq!(