aboutsummaryrefslogtreecommitdiff
path: root/crates/ra_prof/src
diff options
context:
space:
mode:
authorAleksey Kladov <[email protected]>2020-08-12 15:32:36 +0100
committerAleksey Kladov <[email protected]>2020-08-12 15:35:29 +0100
commit208b7bd7ba687fb570feb1b89219f14c63712ce8 (patch)
treec39749d1b71b73b4017c2d0d848ebdc85e570c39 /crates/ra_prof/src
parent98baa9b569b49162392ed4149dd435854fe941b8 (diff)
Rename ra_prof -> profile
Diffstat (limited to 'crates/ra_prof/src')
-rw-r--r--crates/ra_prof/src/google_cpu_profiler.rs39
-rw-r--r--crates/ra_prof/src/hprof.rs243
-rw-r--r--crates/ra_prof/src/lib.rs109
-rw-r--r--crates/ra_prof/src/memory_usage.rs75
-rw-r--r--crates/ra_prof/src/stop_watch.rs86
-rw-r--r--crates/ra_prof/src/tree.rs84
6 files changed, 0 insertions, 636 deletions
diff --git a/crates/ra_prof/src/google_cpu_profiler.rs b/crates/ra_prof/src/google_cpu_profiler.rs
deleted file mode 100644
index db865c65b..000000000
--- a/crates/ra_prof/src/google_cpu_profiler.rs
+++ /dev/null
@@ -1,39 +0,0 @@
1//! https://github.com/gperftools/gperftools
2
3use std::{
4 ffi::CString,
5 os::raw::c_char,
6 path::Path,
7 sync::atomic::{AtomicUsize, Ordering},
8};
9
10#[link(name = "profiler")]
11#[allow(non_snake_case)]
12extern "C" {
13 fn ProfilerStart(fname: *const c_char) -> i32;
14 fn ProfilerStop();
15}
16
17static PROFILER_STATE: AtomicUsize = AtomicUsize::new(OFF);
18const OFF: usize = 0;
19const ON: usize = 1;
20const PENDING: usize = 2;
21
22pub fn start(path: &Path) {
23 if PROFILER_STATE.compare_and_swap(OFF, PENDING, Ordering::SeqCst) != OFF {
24 panic!("profiler already started");
25 }
26 let path = CString::new(path.display().to_string()).unwrap();
27 if unsafe { ProfilerStart(path.as_ptr()) } == 0 {
28 panic!("profiler failed to start")
29 }
30 assert!(PROFILER_STATE.compare_and_swap(PENDING, ON, Ordering::SeqCst) == PENDING);
31}
32
33pub fn stop() {
34 if PROFILER_STATE.compare_and_swap(ON, PENDING, Ordering::SeqCst) != ON {
35 panic!("profiler is not started")
36 }
37 unsafe { ProfilerStop() };
38 assert!(PROFILER_STATE.compare_and_swap(PENDING, OFF, Ordering::SeqCst) == PENDING);
39}
diff --git a/crates/ra_prof/src/hprof.rs b/crates/ra_prof/src/hprof.rs
deleted file mode 100644
index a3f5321fb..000000000
--- a/crates/ra_prof/src/hprof.rs
+++ /dev/null
@@ -1,243 +0,0 @@
1//! Simple hierarchical profiler
2use once_cell::sync::Lazy;
3use std::{
4 cell::RefCell,
5 collections::{BTreeMap, HashSet},
6 io::{stderr, Write},
7 sync::{
8 atomic::{AtomicBool, Ordering},
9 RwLock,
10 },
11 time::{Duration, Instant},
12};
13
14use crate::tree::{Idx, Tree};
15
16/// Filtering syntax
17/// env RA_PROFILE=* // dump everything
18/// env RA_PROFILE=foo|bar|baz // enabled only selected entries
19/// env RA_PROFILE=*@3>10 // dump everything, up to depth 3, if it takes more than 10 ms
20pub fn init() {
21 let spec = std::env::var("RA_PROFILE").unwrap_or_default();
22 init_from(&spec);
23}
24
25pub fn init_from(spec: &str) {
26 let filter = if spec.is_empty() { Filter::disabled() } else { Filter::from_spec(spec) };
27 filter.install();
28}
29
30pub type Label = &'static str;
31
32/// This function starts a profiling scope in the current execution stack with a given description.
33/// It returns a `Profile` struct that measures elapsed time between this method invocation and `Profile` struct drop.
34/// It supports nested profiling scopes in case when this function is invoked multiple times at the execution stack.
35/// In this case the profiling information will be nested at the output.
36/// Profiling information is being printed in the stderr.
37///
38/// # Example
39/// ```
40/// use ra_prof::{profile, set_filter, Filter};
41///
42/// let f = Filter::from_spec("profile1|profile2@2");
43/// set_filter(f);
44/// profiling_function1();
45///
46/// fn profiling_function1() {
47/// let _p = profile("profile1");
48/// profiling_function2();
49/// }
50///
51/// fn profiling_function2() {
52/// let _p = profile("profile2");
53/// }
54/// ```
55/// This will print in the stderr the following:
56/// ```text
57/// 0ms - profile
58/// 0ms - profile2
59/// ```
60pub fn profile(label: Label) -> Profiler {
61 assert!(!label.is_empty());
62
63 if PROFILING_ENABLED.load(Ordering::Relaxed)
64 && PROFILE_STACK.with(|stack| stack.borrow_mut().push(label))
65 {
66 Profiler(Some(ProfilerImpl { label, detail: None }))
67 } else {
68 Profiler(None)
69 }
70}
71
72pub struct Profiler(Option<ProfilerImpl>);
73
74struct ProfilerImpl {
75 label: Label,
76 detail: Option<String>,
77}
78
79impl Profiler {
80 pub fn detail(mut self, detail: impl FnOnce() -> String) -> Profiler {
81 if let Some(profiler) = &mut self.0 {
82 profiler.detail = Some(detail())
83 }
84 self
85 }
86}
87
88impl Drop for ProfilerImpl {
89 fn drop(&mut self) {
90 PROFILE_STACK.with(|it| it.borrow_mut().pop(self.label, self.detail.take()));
91 }
92}
93
94static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false);
95static FILTER: Lazy<RwLock<Filter>> = Lazy::new(Default::default);
96thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new()));
97
98#[derive(Default, Clone, Debug)]
99struct Filter {
100 depth: usize,
101 allowed: HashSet<String>,
102 longer_than: Duration,
103 version: usize,
104}
105
106impl Filter {
107 fn disabled() -> Filter {
108 Filter::default()
109 }
110
111 fn from_spec(mut spec: &str) -> Filter {
112 let longer_than = if let Some(idx) = spec.rfind('>') {
113 let longer_than = spec[idx + 1..].parse().expect("invalid profile longer_than");
114 spec = &spec[..idx];
115 Duration::from_millis(longer_than)
116 } else {
117 Duration::new(0, 0)
118 };
119
120 let depth = if let Some(idx) = spec.rfind('@') {
121 let depth: usize = spec[idx + 1..].parse().expect("invalid profile depth");
122 spec = &spec[..idx];
123 depth
124 } else {
125 999
126 };
127 let allowed =
128 if spec == "*" { HashSet::new() } else { spec.split('|').map(String::from).collect() };
129 Filter { depth, allowed, longer_than, version: 0 }
130 }
131
132 fn install(mut self) {
133 PROFILING_ENABLED.store(self.depth > 0, Ordering::SeqCst);
134 let mut old = FILTER.write().unwrap();
135 self.version = old.version + 1;
136 *old = self;
137 }
138}
139
140struct ProfileStack {
141 starts: Vec<Instant>,
142 filter: Filter,
143 messages: Tree<Message>,
144}
145
146#[derive(Default)]
147struct Message {
148 duration: Duration,
149 label: Label,
150 detail: Option<String>,
151}
152
153impl ProfileStack {
154 fn new() -> ProfileStack {
155 ProfileStack { starts: Vec::new(), messages: Tree::default(), filter: Default::default() }
156 }
157
158 fn push(&mut self, label: Label) -> bool {
159 if self.starts.is_empty() {
160 if let Ok(f) = FILTER.try_read() {
161 if f.version > self.filter.version {
162 self.filter = f.clone();
163 }
164 };
165 }
166 if self.starts.len() > self.filter.depth {
167 return false;
168 }
169 let allowed = &self.filter.allowed;
170 if self.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) {
171 return false;
172 }
173
174 self.starts.push(Instant::now());
175 self.messages.start();
176 true
177 }
178
179 pub fn pop(&mut self, label: Label, detail: Option<String>) {
180 let start = self.starts.pop().unwrap();
181 let duration = start.elapsed();
182 self.messages.finish(Message { duration, label, detail });
183 if self.starts.is_empty() {
184 let longer_than = self.filter.longer_than;
185 // Convert to millis for comparison to avoid problems with rounding
186 // (otherwise we could print `0ms` despite user's `>0` filter when
187 // `duration` is just a few nanos).
188 if duration.as_millis() > longer_than.as_millis() {
189 if let Some(root) = self.messages.root() {
190 print(&self.messages, root, 0, longer_than, &mut stderr().lock());
191 }
192 }
193 self.messages.clear();
194 }
195 }
196}
197
198fn print(
199 tree: &Tree<Message>,
200 curr: Idx<Message>,
201 level: u32,
202 longer_than: Duration,
203 out: &mut impl Write,
204) {
205 let current_indent = " ".repeat(level as usize);
206 let detail = tree[curr].detail.as_ref().map(|it| format!(" @ {}", it)).unwrap_or_default();
207 writeln!(
208 out,
209 "{}{:5}ms - {}{}",
210 current_indent,
211 tree[curr].duration.as_millis(),
212 tree[curr].label,
213 detail,
214 )
215 .expect("printing profiling info");
216
217 let mut accounted_for = Duration::default();
218 let mut short_children = BTreeMap::new(); // Use `BTreeMap` to get deterministic output.
219 for child in tree.children(curr) {
220 accounted_for += tree[child].duration;
221
222 if tree[child].duration.as_millis() > longer_than.as_millis() {
223 print(tree, child, level + 1, longer_than, out)
224 } else {
225 let (total_duration, cnt) =
226 short_children.entry(tree[child].label).or_insert((Duration::default(), 0));
227 *total_duration += tree[child].duration;
228 *cnt += 1;
229 }
230 }
231
232 for (child_msg, (duration, count)) in short_children.iter() {
233 let millis = duration.as_millis();
234 writeln!(out, " {}{:5}ms - {} ({} calls)", current_indent, millis, child_msg, count)
235 .expect("printing profiling info");
236 }
237
238 let unaccounted = tree[curr].duration - accounted_for;
239 if tree.children(curr).next().is_some() && unaccounted > longer_than {
240 writeln!(out, " {}{:5}ms - ???", current_indent, unaccounted.as_millis())
241 .expect("printing profiling info");
242 }
243}
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
deleted file mode 100644
index eb50965ae..000000000
--- a/crates/ra_prof/src/lib.rs
+++ /dev/null
@@ -1,109 +0,0 @@
1//! A collection of tools for profiling rust-analyzer.
2
3mod stop_watch;
4mod memory_usage;
5#[cfg(feature = "cpu_profiler")]
6mod google_cpu_profiler;
7mod hprof;
8mod tree;
9
10use std::cell::RefCell;
11
12pub use crate::{
13 hprof::{init, init_from, profile},
14 memory_usage::{Bytes, MemoryUsage},
15 stop_watch::{StopWatch, StopWatchSpan},
16};
17
18/// Prints backtrace to stderr, useful for debugging.
19#[cfg(feature = "backtrace")]
20pub fn print_backtrace() {
21 let bt = backtrace::Backtrace::new();
22 eprintln!("{:?}", bt);
23}
24#[cfg(not(feature = "backtrace"))]
25pub fn print_backtrace() {
26 eprintln!(
27 r#"enable the backtrace feature:
28 ra_prof = {{ path = "../ra_prof", features = [ "backtrace"] }}
29"#
30 );
31}
32
33thread_local!(static IN_SCOPE: RefCell<bool> = RefCell::new(false));
34
35/// Allows to check if the current code is withing some dynamic scope, can be
36/// useful during debugging to figure out why a function is called.
37pub struct Scope {
38 prev: bool,
39}
40
41impl Scope {
42 #[must_use]
43 pub fn enter() -> Scope {
44 let prev = IN_SCOPE.with(|slot| std::mem::replace(&mut *slot.borrow_mut(), true));
45 Scope { prev }
46 }
47 pub fn is_active() -> bool {
48 IN_SCOPE.with(|slot| *slot.borrow())
49 }
50}
51
52impl Drop for Scope {
53 fn drop(&mut self) {
54 IN_SCOPE.with(|slot| *slot.borrow_mut() = self.prev);
55 }
56}
57
58/// A wrapper around google_cpu_profiler.
59///
60/// Usage:
61/// 1. Install gpref_tools (https://github.com/gperftools/gperftools), probably packaged with your Linux distro.
62/// 2. Build with `cpu_profiler` feature.
63/// 3. Tun the code, the *raw* output would be in the `./out.profile` file.
64/// 4. Install pprof for visualization (https://github.com/google/pprof).
65/// 5. Bump sampling frequency to once per ms: `export CPUPROFILE_FREQUENCY=1000`
66/// 6. Use something like `pprof -svg target/release/rust-analyzer ./out.profile` to see the results.
67///
68/// For example, here's how I run profiling on NixOS:
69///
70/// ```bash
71/// $ nix-shell -p gperftools --run \
72/// 'cargo run --release -p rust-analyzer -- parse < ~/projects/rustbench/parser.rs > /dev/null'
73/// ```
74///
75/// See this diff for how to profile completions:
76///
77/// https://github.com/rust-analyzer/rust-analyzer/pull/5306
78#[derive(Debug)]
79pub struct CpuProfiler {
80 _private: (),
81}
82
83#[must_use]
84pub fn cpu_profiler() -> CpuProfiler {
85 #[cfg(feature = "cpu_profiler")]
86 {
87 google_cpu_profiler::start("./out.profile".as_ref())
88 }
89
90 #[cfg(not(feature = "cpu_profiler"))]
91 {
92 eprintln!("cpu_profiler feature is disabled")
93 }
94
95 CpuProfiler { _private: () }
96}
97
98impl Drop for CpuProfiler {
99 fn drop(&mut self) {
100 #[cfg(feature = "cpu_profiler")]
101 {
102 google_cpu_profiler::stop()
103 }
104 }
105}
106
107pub fn memory_usage() -> MemoryUsage {
108 MemoryUsage::current()
109}
diff --git a/crates/ra_prof/src/memory_usage.rs b/crates/ra_prof/src/memory_usage.rs
deleted file mode 100644
index 83390212a..000000000
--- a/crates/ra_prof/src/memory_usage.rs
+++ /dev/null
@@ -1,75 +0,0 @@
1//! FIXME: write short doc here
2use std::fmt;
3
4use cfg_if::cfg_if;
5
6#[derive(Copy, Clone)]
7pub struct MemoryUsage {
8 pub allocated: Bytes,
9}
10
11impl fmt::Display for MemoryUsage {
12 fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
13 write!(fmt, "{}", self.allocated)
14 }
15}
16
17impl std::ops::Sub for MemoryUsage {
18 type Output = MemoryUsage;
19 fn sub(self, rhs: MemoryUsage) -> MemoryUsage {
20 MemoryUsage { allocated: self.allocated - rhs.allocated }
21 }
22}
23
24impl MemoryUsage {
25 pub fn current() -> MemoryUsage {
26 cfg_if! {
27 if #[cfg(all(target_os = "linux", target_env = "gnu"))] {
28 // Note: This is incredibly slow.
29 let alloc = unsafe { libc::mallinfo() }.uordblks as isize;
30 MemoryUsage { allocated: Bytes(alloc) }
31 } else {
32 MemoryUsage { allocated: Bytes(0) }
33 }
34 }
35 }
36}
37
38#[derive(Default, PartialEq, Eq, PartialOrd, Ord, Hash, Clone, Copy)]
39pub struct Bytes(isize);
40
41impl Bytes {
42 pub fn megabytes(self) -> isize {
43 self.0 / 1024 / 1024
44 }
45}
46
47impl fmt::Display for Bytes {
48 fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
49 let bytes = self.0;
50 let mut value = bytes;
51 let mut suffix = "b";
52 if value.abs() > 4096 {
53 value /= 1024;
54 suffix = "kb";
55 if value.abs() > 4096 {
56 value /= 1024;
57 suffix = "mb";
58 }
59 }
60 f.pad(&format!("{}{}", value, suffix))
61 }
62}
63
64impl std::ops::AddAssign<usize> for Bytes {
65 fn add_assign(&mut self, x: usize) {
66 self.0 += x as isize;
67 }
68}
69
70impl std::ops::Sub for Bytes {
71 type Output = Bytes;
72 fn sub(self, rhs: Bytes) -> Bytes {
73 Bytes(self.0 - rhs.0)
74 }
75}
diff --git a/crates/ra_prof/src/stop_watch.rs b/crates/ra_prof/src/stop_watch.rs
deleted file mode 100644
index 5e276190e..000000000
--- a/crates/ra_prof/src/stop_watch.rs
+++ /dev/null
@@ -1,86 +0,0 @@
1//! Like `std::time::Instant`, but also measures memory & CPU cycles.
2use std::{
3 fmt,
4 time::{Duration, Instant},
5};
6
7use crate::MemoryUsage;
8
9pub struct StopWatch {
10 time: Instant,
11 #[cfg(target_os = "linux")]
12 counter: Option<perf_event::Counter>,
13 memory: Option<MemoryUsage>,
14}
15
16pub struct StopWatchSpan {
17 pub time: Duration,
18 pub instructions: Option<u64>,
19 pub memory: Option<MemoryUsage>,
20}
21
22impl StopWatch {
23 pub fn start() -> StopWatch {
24 #[cfg(target_os = "linux")]
25 let counter = {
26 let mut counter = perf_event::Builder::new()
27 .build()
28 .map_err(|err| eprintln!("Failed to create perf counter: {}", err))
29 .ok();
30 if let Some(counter) = &mut counter {
31 if let Err(err) = counter.enable() {
32 eprintln!("Failed to start perf counter: {}", err)
33 }
34 }
35 counter
36 };
37 let time = Instant::now();
38 StopWatch {
39 time,
40 #[cfg(target_os = "linux")]
41 counter,
42 memory: None,
43 }
44 }
45 pub fn memory(mut self, yes: bool) -> StopWatch {
46 if yes {
47 self.memory = Some(MemoryUsage::current());
48 }
49 self
50 }
51 pub fn elapsed(&mut self) -> StopWatchSpan {
52 let time = self.time.elapsed();
53
54 #[cfg(target_os = "linux")]
55 let instructions = self.counter.as_mut().and_then(|it| {
56 it.read().map_err(|err| eprintln!("Failed to read perf counter: {}", err)).ok()
57 });
58 #[cfg(not(target_os = "linux"))]
59 let instructions = None;
60
61 let memory = self.memory.map(|it| MemoryUsage::current() - it);
62 StopWatchSpan { time, instructions, memory }
63 }
64}
65
66impl fmt::Display for StopWatchSpan {
67 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
68 write!(f, "{:.2?}", self.time)?;
69 if let Some(mut instructions) = self.instructions {
70 let mut prefix = "";
71 if instructions > 10000 {
72 instructions /= 1000;
73 prefix = "k"
74 }
75 if instructions > 10000 {
76 instructions /= 1000;
77 prefix = "m"
78 }
79 write!(f, ", {}{}i", instructions, prefix)?;
80 }
81 if let Some(memory) = self.memory {
82 write!(f, ", {}", memory)?;
83 }
84 Ok(())
85 }
86}
diff --git a/crates/ra_prof/src/tree.rs b/crates/ra_prof/src/tree.rs
deleted file mode 100644
index 096f58511..000000000
--- a/crates/ra_prof/src/tree.rs
+++ /dev/null
@@ -1,84 +0,0 @@
1//! A simple tree implementation which tries to not allocate all over the place.
2use std::ops;
3
4use arena::Arena;
5
6#[derive(Default)]
7pub struct Tree<T> {
8 nodes: Arena<Node<T>>,
9 current_path: Vec<(Idx<T>, Option<Idx<T>>)>,
10}
11
12pub type Idx<T> = arena::Idx<Node<T>>;
13
14impl<T> Tree<T> {
15 pub fn start(&mut self)
16 where
17 T: Default,
18 {
19 let me = self.nodes.alloc(Node::new(T::default()));
20 if let Some((parent, last_child)) = self.current_path.last_mut() {
21 let slot = match *last_child {
22 Some(last_child) => &mut self.nodes[last_child].next_sibling,
23 None => &mut self.nodes[*parent].first_child,
24 };
25 let prev = slot.replace(me);
26 assert!(prev.is_none());
27 *last_child = Some(me);
28 }
29
30 self.current_path.push((me, None));
31 }
32
33 pub fn finish(&mut self, data: T) {
34 let (me, _last_child) = self.current_path.pop().unwrap();
35 self.nodes[me].data = data;
36 }
37
38 pub fn root(&self) -> Option<Idx<T>> {
39 self.nodes.iter().next().map(|(idx, _)| idx)
40 }
41
42 pub fn children(&self, idx: Idx<T>) -> impl Iterator<Item = Idx<T>> + '_ {
43 NodeIter { nodes: &self.nodes, next: self.nodes[idx].first_child }
44 }
45 pub fn clear(&mut self) {
46 self.nodes.clear();
47 self.current_path.clear();
48 }
49}
50
51impl<T> ops::Index<Idx<T>> for Tree<T> {
52 type Output = T;
53 fn index(&self, index: Idx<T>) -> &T {
54 &self.nodes[index].data
55 }
56}
57
58pub struct Node<T> {
59 data: T,
60 first_child: Option<Idx<T>>,
61 next_sibling: Option<Idx<T>>,
62}
63
64impl<T> Node<T> {
65 fn new(data: T) -> Node<T> {
66 Node { data, first_child: None, next_sibling: None }
67 }
68}
69
70struct NodeIter<'a, T> {
71 nodes: &'a Arena<Node<T>>,
72 next: Option<Idx<T>>,
73}
74
75impl<'a, T> Iterator for NodeIter<'a, T> {
76 type Item = Idx<T>;
77
78 fn next(&mut self) -> Option<Idx<T>> {
79 self.next.map(|next| {
80 self.next = self.nodes[next].next_sibling;
81 next
82 })
83 }
84}
generated by cgit v1.2.3 (git 2.25.1) at 2024-12-03 17:54:12 +0000