Simplify hprof

This commit is contained in:
Aleksey Kladov 2020-04-25 19:29:41 +02:00
parent b3e9f3d143
commit 726938f598

View file

@ -23,7 +23,7 @@ pub fn init() {
pub fn init_from(spec: &str) { pub fn init_from(spec: &str) {
let filter = if spec.is_empty() { Filter::disabled() } else { Filter::from_spec(spec) }; let filter = if spec.is_empty() { Filter::disabled() } else { Filter::from_spec(spec) };
set_filter(filter); filter.install();
} }
pub type Label = &'static str; pub type Label = &'static str;
@ -57,30 +57,10 @@ pub type Label = &'static str;
/// ``` /// ```
pub fn profile(label: Label) -> Profiler { pub fn profile(label: Label) -> Profiler {
assert!(!label.is_empty()); assert!(!label.is_empty());
if !PROFILING_ENABLED.load(Ordering::Relaxed) { let enabled = PROFILING_ENABLED.load(Ordering::Relaxed)
return Profiler { label: None, detail: None }; && PROFILE_STACK.with(|stack| stack.borrow_mut().push(label));
} let label = if enabled { Some(label) } else { None };
Profiler { label, detail: None }
PROFILE_STACK.with(|stack| {
let mut stack = stack.borrow_mut();
if stack.starts.is_empty() {
if let Ok(f) = FILTER.try_read() {
if f.version > stack.filter_data.version {
stack.filter_data = f.clone();
}
};
}
if stack.starts.len() > stack.filter_data.depth {
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, detail: None };
}
stack.starts.push(Instant::now());
Profiler { label: Some(label), detail: None }
})
} }
pub struct Profiler { pub struct Profiler {
@ -97,36 +77,27 @@ impl Profiler {
} }
} }
/// Set profiling filter. It specifies descriptions allowed to profile. static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false);
/// This is helpful when call stack has too many nested profiling scopes. static FILTER: Lazy<RwLock<Filter>> = Lazy::new(Default::default);
/// Additionally filter can specify maximum depth of profiling scopes nesting. thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new()));
///
/// #Example
/// ```
/// use ra_prof::{set_filter, Filter};
/// let f = Filter::from_spec("profile1|profile2@2");
/// set_filter(f);
/// ```
fn set_filter(f: Filter) {
PROFILING_ENABLED.store(f.depth > 0, Ordering::SeqCst);
let set: HashSet<_> = f.allowed.iter().cloned().collect();
let mut old = FILTER.write().unwrap();
let filter_data = FilterData {
depth: f.depth,
allowed: set,
longer_than: f.longer_than,
version: old.version + 1,
};
*old = filter_data;
}
#[derive(Default, Clone, Debug)]
struct Filter { struct Filter {
depth: usize, depth: usize,
allowed: Vec<String>, allowed: HashSet<String>,
longer_than: Duration, longer_than: Duration,
version: usize,
} }
impl Filter { impl Filter {
fn new(depth: usize, allowed: HashSet<String>, longer_than: Duration) -> Filter {
Filter { depth, allowed, longer_than, version: 0 }
}
fn disabled() -> Filter {
Filter::default()
}
fn from_spec(mut spec: &str) -> Filter { fn from_spec(mut spec: &str) -> Filter {
let longer_than = if let Some(idx) = spec.rfind('>') { let longer_than = if let Some(idx) = spec.rfind('>') {
let longer_than = spec[idx + 1..].parse().expect("invalid profile longer_than"); let longer_than = spec[idx + 1..].parse().expect("invalid profile longer_than");
@ -144,23 +115,22 @@ impl Filter {
999 999
}; };
let allowed = let allowed =
if spec == "*" { Vec::new() } else { spec.split('|').map(String::from).collect() }; if spec == "*" { HashSet::new() } else { spec.split('|').map(String::from).collect() };
Filter::new(depth, allowed, longer_than) Filter::new(depth, allowed, longer_than)
} }
pub fn disabled() -> Filter { fn install(mut self) {
Filter::new(0, Vec::new(), Duration::new(0, 0)) PROFILING_ENABLED.store(self.depth > 0, Ordering::SeqCst);
} let mut old = FILTER.write().unwrap();
self.version = old.version + 1;
pub fn new(depth: usize, allowed: Vec<String>, longer_than: Duration) -> Filter { *old = self;
Filter { depth, allowed, longer_than }
} }
} }
struct ProfileStack { struct ProfileStack {
starts: Vec<Instant>, starts: Vec<Instant>,
messages: Vec<Message>, messages: Vec<Message>,
filter_data: FilterData, filter: Filter,
} }
struct Message { struct Message {
@ -172,45 +142,54 @@ struct Message {
impl ProfileStack { impl ProfileStack {
fn new() -> ProfileStack { fn new() -> ProfileStack {
ProfileStack { starts: Vec::new(), messages: Vec::new(), filter_data: Default::default() } ProfileStack { starts: Vec::new(), messages: Vec::new(), filter: Default::default() }
}
fn push(&mut self, label: Label) -> bool {
if self.starts.is_empty() {
if let Ok(f) = FILTER.try_read() {
if f.version > self.filter.version {
self.filter = f.clone();
}
};
}
if self.starts.len() > self.filter.depth {
return false;
}
let allowed = &self.filter.allowed;
if self.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) {
return false;
}
self.starts.push(Instant::now());
true
}
pub fn pop(&mut self, label: Label, detail: Option<String>) {
let start = self.starts.pop().unwrap();
let duration = start.elapsed();
let level = self.starts.len();
self.messages.push(Message { level, duration, label, detail });
if level == 0 {
let stdout = stderr();
let longer_than = self.filter.longer_than;
// Convert to millis for comparison to avoid problems with rounding
// (otherwise we could print `0ms` despite user's `>0` filter when
// `duration` is just a few nanos).
if duration.as_millis() > longer_than.as_millis() {
print(&self.messages, longer_than, &mut stdout.lock());
}
self.messages.clear();
}
} }
} }
#[derive(Default, Clone)]
struct FilterData {
depth: usize,
version: usize,
allowed: HashSet<String>,
longer_than: Duration,
}
static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false);
static FILTER: Lazy<RwLock<FilterData>> = Lazy::new(Default::default);
thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new()));
impl Drop for Profiler { impl Drop for Profiler {
fn drop(&mut self) { fn drop(&mut self) {
match self { match self {
Profiler { label: Some(label), detail } => { Profiler { label: Some(label), detail } => {
PROFILE_STACK.with(|stack| { PROFILE_STACK.with(|stack| {
let mut stack = stack.borrow_mut(); stack.borrow_mut().pop(label, detail.take());
let start = stack.starts.pop().unwrap();
let duration = start.elapsed();
let level = stack.starts.len();
stack.messages.push(Message { level, duration, label, detail: detail.take() });
if level == 0 {
let stdout = stderr();
let longer_than = stack.filter_data.longer_than;
// Convert to millis for comparison to avoid problems with rounding
// (otherwise we could print `0ms` despite user's `>0` filter when
// `duration` is just a few nanos).
if duration.as_millis() > longer_than.as_millis() {
print(&stack.messages, longer_than, &mut stdout.lock());
}
stack.messages.clear();
}
}); });
} }
Profiler { label: None, .. } => (), Profiler { label: None, .. } => (),