mathieu/granite-rust
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity

Allow specifying additional info on call to profile

Browse source
This commit is contained in:
Aleksey Kladov 2020-03-06 17:23:08 +01:00
parent 59f91f2f9b
commit b33b843f40
3 changed files with 52 additions and 21 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

11
crates/ra_hir_ty/src/db.rs
View file

@ -16,6 +16,7 @@ use crate::{
Binders, CallableDef, GenericPredicate, InferenceResult, PolyFnSig, Substs, TraitRef, Ty,
TyDefId, TypeCtor, ValueTyDefId,
};
use hir_expand::name::Name;
#[salsa::query_group(HirDatabaseStorage)]
#[salsa::requires(salsa::Database)]
@ -111,7 +112,15 @@ pub trait HirDatabase: DefDatabase {
}
fn infer(db: &impl HirDatabase, def: DefWithBodyId) -> Arc<InferenceResult> {
let _p = profile("wait_infer");
let _p = profile("wait_infer").detail(|| match def {
DefWithBodyId::FunctionId(it) => db.function_data(it).name.to_string(),
DefWithBodyId::StaticId(it) => {
db.static_data(it).name.clone().unwrap_or_else(Name::missing).to_string()
}
DefWithBodyId::ConstId(it) => {
db.const_data(it).name.clone().unwrap_or_else(Name::missing).to_string()
}
});
db.do_infer(def)
}

5
crates/ra_hir_ty/src/traits.rs
View file

@ -221,7 +221,10 @@ pub(crate) fn trait_solve_query(
krate: CrateId,
goal: Canonical<InEnvironment<Obligation>>,
) -> Option<Solution> {
let _p = profile("trait_solve_query");
let _p = profile("trait_solve_query").detail(|| match &goal.value.value {
Obligation::Trait(it) => db.trait_data(it.trait_).name.to_string(),
Obligation::Projection(_) => "projection".to_string(),
});
log::debug!("trait_solve_query({})", goal.value.value.display(db));
if let Obligation::Projection(pred) = &goal.value.value {

57
crates/ra_prof/src/lib.rs
View file

@ -88,7 +88,7 @@ pub type Label = &'static str;
pub fn profile(label: Label) -> Profiler {
assert!(!label.is_empty());
if !PROFILING_ENABLED.load(Ordering::Relaxed) {
return Profiler { label: None };
return Profiler { label: None, detail: None };
}
PROFILE_STACK.with(|stack| {
@ -101,15 +101,15 @@ pub fn profile(label: Label) -> Profiler {
};
}
if stack.starts.len() > stack.filter_data.depth {
return Profiler { label: None };
return Profiler { label: None, detail: None };
}
let allowed = &stack.filter_data.allowed;
if stack.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) {
return Profiler { label: None };
return Profiler { label: None, detail: None };
}
stack.starts.push(Instant::now());
Profiler { label: Some(label) }
Profiler { label: Some(label), detail: None }
})
}
@ -130,6 +130,16 @@ pub fn print_time(label: Label) -> impl Drop {
pub struct Profiler {
label: Option<Label>,
detail: Option<String>,
}
impl Profiler {
pub fn detail(mut self, detail: impl FnOnce() -> String) -> Profiler {
if self.label.is_some() {
self.detail = Some(detail())
}
self
}
}
pub struct Filter {
@ -183,6 +193,7 @@ struct Message {
level: usize,
duration: Duration,
label: Label,
detail: Option<String>,
}
impl ProfileStack {
@ -208,13 +219,13 @@ thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(Profile
impl Drop for Profiler {
fn drop(&mut self) {
match self {
Profiler { label: Some(label) } => {
Profiler { label: Some(label), detail } => {
PROFILE_STACK.with(|stack| {
let mut stack = stack.borrow_mut();
let start = stack.starts.pop().unwrap();
let duration = start.elapsed();
let level = stack.starts.len();
stack.messages.push(Message { level, duration, label });
stack.messages.push(Message { level, duration, label, detail: detail.take() });
if level == 0 {
let stdout = stderr();
let longer_than = stack.filter_data.longer_than;
@ -228,7 +239,7 @@ impl Drop for Profiler {
}
});
}
Profiler { label: None } => (),
Profiler { label: None, .. } => (),
}
}
}
@ -251,8 +262,16 @@ fn print_for_idx(
) {
let current = &msgs[current_idx];
let current_indent = " ".repeat(current.level);
writeln!(out, "{}{:5}ms - {}", current_indent, current.duration.as_millis(), current.label)
.expect("printing profiling info");
let detail = current.detail.as_ref().map(|it| format!(" @ {}", it)).unwrap_or_default();
writeln!(
out,
"{}{:5}ms - {}{}",
current_indent,
current.duration.as_millis(),
current.label,
detail,
)
.expect("printing profiling info");
let longer_than_millis = longer_than.as_millis();
let children_indices = &children_map[current_idx];
@ -417,9 +436,9 @@ mod tests {
fn test_longer_than() {
let mut result = vec![];
let msgs = vec![
Message { level: 1, duration: Duration::from_nanos(3), label: "bar" },
Message { level: 1, duration: Duration::from_nanos(2), label: "bar" },
Message { level: 0, duration: Duration::from_millis(1), label: "foo" },
Message { level: 1, duration: Duration::from_nanos(3), label: "bar", detail: None },
Message { level: 1, duration: Duration::from_nanos(2), label: "bar", detail: None },
Message { level: 0, duration: Duration::from_millis(1), label: "foo", detail: None },
];
print(&msgs, Duration::from_millis(0), &mut result);
// The calls to `bar` are so short that they'll be rounded to 0ms and should get collapsed
@ -434,8 +453,8 @@ mod tests {
fn test_unaccounted_for_topmost() {
let mut result = vec![];
let msgs = vec![
Message { level: 1, duration: Duration::from_millis(2), label: "bar" },
Message { level: 0, duration: Duration::from_millis(5), label: "foo" },
Message { level: 1, duration: Duration::from_millis(2), label: "bar", detail: None },
Message { level: 0, duration: Duration::from_millis(5), label: "foo", detail: None },
];
print(&msgs, Duration::from_millis(0), &mut result);
assert_eq!(
@ -453,11 +472,11 @@ mod tests {
fn test_unaccounted_for_multiple_levels() {
let mut result = vec![];
let msgs = vec![
Message { level: 2, duration: Duration::from_millis(3), label: "baz" },
Message { level: 1, duration: Duration::from_millis(5), label: "bar" },
Message { level: 2, duration: Duration::from_millis(2), label: "baz" },
Message { level: 1, duration: Duration::from_millis(4), label: "bar" },
Message { level: 0, duration: Duration::from_millis(9), label: "foo" },
Message { level: 2, duration: Duration::from_millis(3), label: "baz", detail: None },
Message { level: 1, duration: Duration::from_millis(5), label: "bar", detail: None },
Message { level: 2, duration: Duration::from_millis(2), label: "baz", detail: None },
Message { level: 1, duration: Duration::from_millis(4), label: "bar", detail: None },
Message { level: 0, duration: Duration::from_millis(9), label: "foo", detail: None },
];
print(&msgs, Duration::from_millis(0), &mut result);
assert_eq!(