aboutsummaryrefslogtreecommitdiff
path: root/crates
diff options
context:
space:
mode:
authorAleksey Kladov <[email protected]>2020-03-06 16:23:08 +0000
committerAleksey Kladov <[email protected]>2020-03-06 16:36:51 +0000
commitb33b843f408fe73bde920c087de0622f46e853e5 (patch)
treed6b5eea44ab7bb61cc3b66e622ffb0031b54d777 /crates
parent59f91f2f9ba4cb6fa86fccb8a427cb9af2ecd192 (diff)
Allow specifying additional info on call to profile
Diffstat (limited to 'crates')
-rw-r--r--crates/ra_hir_ty/src/db.rs11
-rw-r--r--crates/ra_hir_ty/src/traits.rs5
-rw-r--r--crates/ra_prof/src/lib.rs57
3 files changed, 52 insertions, 21 deletions
diff --git a/crates/ra_hir_ty/src/db.rs b/crates/ra_hir_ty/src/db.rs
index c43619d1c..f79faa84d 100644
--- a/crates/ra_hir_ty/src/db.rs
+++ b/crates/ra_hir_ty/src/db.rs
@@ -16,6 +16,7 @@ use crate::{
16 Binders, CallableDef, GenericPredicate, InferenceResult, PolyFnSig, Substs, TraitRef, Ty, 16 Binders, CallableDef, GenericPredicate, InferenceResult, PolyFnSig, Substs, TraitRef, Ty,
17 TyDefId, TypeCtor, ValueTyDefId, 17 TyDefId, TypeCtor, ValueTyDefId,
18}; 18};
19use hir_expand::name::Name;
19 20
20#[salsa::query_group(HirDatabaseStorage)] 21#[salsa::query_group(HirDatabaseStorage)]
21#[salsa::requires(salsa::Database)] 22#[salsa::requires(salsa::Database)]
@@ -111,7 +112,15 @@ pub trait HirDatabase: DefDatabase {
111} 112}
112 113
113fn infer(db: &impl HirDatabase, def: DefWithBodyId) -> Arc<InferenceResult> { 114fn infer(db: &impl HirDatabase, def: DefWithBodyId) -> Arc<InferenceResult> {
114 let _p = profile("wait_infer"); 115 let _p = profile("wait_infer").detail(|| match def {
116 DefWithBodyId::FunctionId(it) => db.function_data(it).name.to_string(),
117 DefWithBodyId::StaticId(it) => {
118 db.static_data(it).name.clone().unwrap_or_else(Name::missing).to_string()
119 }
120 DefWithBodyId::ConstId(it) => {
121 db.const_data(it).name.clone().unwrap_or_else(Name::missing).to_string()
122 }
123 });
115 db.do_infer(def) 124 db.do_infer(def)
116} 125}
117 126
diff --git a/crates/ra_hir_ty/src/traits.rs b/crates/ra_hir_ty/src/traits.rs
index bc6ee2600..bdf23ac02 100644
--- a/crates/ra_hir_ty/src/traits.rs
+++ b/crates/ra_hir_ty/src/traits.rs
@@ -221,7 +221,10 @@ pub(crate) fn trait_solve_query(
221 krate: CrateId, 221 krate: CrateId,
222 goal: Canonical<InEnvironment<Obligation>>, 222 goal: Canonical<InEnvironment<Obligation>>,
223) -> Option<Solution> { 223) -> Option<Solution> {
224 let _p = profile("trait_solve_query"); 224 let _p = profile("trait_solve_query").detail(|| match &goal.value.value {
225 Obligation::Trait(it) => db.trait_data(it.trait_).name.to_string(),
226 Obligation::Projection(_) => "projection".to_string(),
227 });
225 log::debug!("trait_solve_query({})", goal.value.value.display(db)); 228 log::debug!("trait_solve_query({})", goal.value.value.display(db));
226 229
227 if let Obligation::Projection(pred) = &goal.value.value { 230 if let Obligation::Projection(pred) = &goal.value.value {
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!(