diff options
-rw-r--r-- | crates/ra_prof/src/hprof.rs | 149 |
1 files changed, 64 insertions, 85 deletions
diff --git a/crates/ra_prof/src/hprof.rs b/crates/ra_prof/src/hprof.rs index 79268513d..6d91206ae 100644 --- a/crates/ra_prof/src/hprof.rs +++ b/crates/ra_prof/src/hprof.rs | |||
@@ -23,7 +23,7 @@ pub fn init() { | |||
23 | 23 | ||
24 | pub fn init_from(spec: &str) { | 24 | pub fn init_from(spec: &str) { |
25 | let filter = if spec.is_empty() { Filter::disabled() } else { Filter::from_spec(spec) }; | 25 | let filter = if spec.is_empty() { Filter::disabled() } else { Filter::from_spec(spec) }; |
26 | set_filter(filter); | 26 | filter.install(); |
27 | } | 27 | } |
28 | 28 | ||
29 | pub type Label = &'static str; | 29 | pub type Label = &'static str; |
@@ -57,30 +57,10 @@ pub type Label = &'static str; | |||
57 | /// ``` | 57 | /// ``` |
58 | pub fn profile(label: Label) -> Profiler { | 58 | pub fn profile(label: Label) -> Profiler { |
59 | assert!(!label.is_empty()); | 59 | assert!(!label.is_empty()); |
60 | if !PROFILING_ENABLED.load(Ordering::Relaxed) { | 60 | let enabled = PROFILING_ENABLED.load(Ordering::Relaxed) |
61 | return Profiler { label: None, detail: None }; | 61 | && PROFILE_STACK.with(|stack| stack.borrow_mut().push(label)); |
62 | } | 62 | let label = if enabled { Some(label) } else { None }; |
63 | 63 | Profiler { label, detail: None } | |
64 | PROFILE_STACK.with(|stack| { | ||
65 | let mut stack = stack.borrow_mut(); | ||
66 | if stack.starts.is_empty() { | ||
67 | if let Ok(f) = FILTER.try_read() { | ||
68 | if f.version > stack.filter_data.version { | ||
69 | stack.filter_data = f.clone(); | ||
70 | } | ||
71 | }; | ||
72 | } | ||
73 | if stack.starts.len() > stack.filter_data.depth { | ||
74 | return Profiler { label: None, detail: None }; | ||
75 | } | ||
76 | let allowed = &stack.filter_data.allowed; | ||
77 | if stack.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) { | ||
78 | return Profiler { label: None, detail: None }; | ||
79 | } | ||
80 | |||
81 | stack.starts.push(Instant::now()); | ||
82 | Profiler { label: Some(label), detail: None } | ||
83 | }) | ||
84 | } | 64 | } |
85 | 65 | ||
86 | pub struct Profiler { | 66 | pub struct Profiler { |
@@ -97,36 +77,27 @@ impl Profiler { | |||
97 | } | 77 | } |
98 | } | 78 | } |
99 | 79 | ||
100 | /// Set profiling filter. It specifies descriptions allowed to profile. | 80 | static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false); |
101 | /// This is helpful when call stack has too many nested profiling scopes. | 81 | static FILTER: Lazy<RwLock<Filter>> = Lazy::new(Default::default); |
102 | /// Additionally filter can specify maximum depth of profiling scopes nesting. | 82 | thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new())); |
103 | /// | ||
104 | /// #Example | ||
105 | /// ``` | ||
106 | /// use ra_prof::{set_filter, Filter}; | ||
107 | /// let f = Filter::from_spec("profile1|profile2@2"); | ||
108 | /// set_filter(f); | ||
109 | /// ``` | ||
110 | fn set_filter(f: Filter) { | ||
111 | PROFILING_ENABLED.store(f.depth > 0, Ordering::SeqCst); | ||
112 | let set: HashSet<_> = f.allowed.iter().cloned().collect(); | ||
113 | let mut old = FILTER.write().unwrap(); | ||
114 | let filter_data = FilterData { | ||
115 | depth: f.depth, | ||
116 | allowed: set, | ||
117 | longer_than: f.longer_than, | ||
118 | version: old.version + 1, | ||
119 | }; | ||
120 | *old = filter_data; | ||
121 | } | ||
122 | 83 | ||
84 | #[derive(Default, Clone, Debug)] | ||
123 | struct Filter { | 85 | struct Filter { |
124 | depth: usize, | 86 | depth: usize, |
125 | allowed: Vec<String>, | 87 | allowed: HashSet<String>, |
126 | longer_than: Duration, | 88 | longer_than: Duration, |
89 | version: usize, | ||
127 | } | 90 | } |
128 | 91 | ||
129 | impl Filter { | 92 | impl Filter { |
93 | fn new(depth: usize, allowed: HashSet<String>, longer_than: Duration) -> Filter { | ||
94 | Filter { depth, allowed, longer_than, version: 0 } | ||
95 | } | ||
96 | |||
97 | fn disabled() -> Filter { | ||
98 | Filter::default() | ||
99 | } | ||
100 | |||
130 | fn from_spec(mut spec: &str) -> Filter { | 101 | fn from_spec(mut spec: &str) -> Filter { |
131 | let longer_than = if let Some(idx) = spec.rfind('>') { | 102 | let longer_than = if let Some(idx) = spec.rfind('>') { |
132 | let longer_than = spec[idx + 1..].parse().expect("invalid profile longer_than"); | 103 | let longer_than = spec[idx + 1..].parse().expect("invalid profile longer_than"); |
@@ -144,23 +115,22 @@ impl Filter { | |||
144 | 999 | 115 | 999 |
145 | }; | 116 | }; |
146 | let allowed = | 117 | let allowed = |
147 | if spec == "*" { Vec::new() } else { spec.split('|').map(String::from).collect() }; | 118 | if spec == "*" { HashSet::new() } else { spec.split('|').map(String::from).collect() }; |
148 | Filter::new(depth, allowed, longer_than) | 119 | Filter::new(depth, allowed, longer_than) |
149 | } | 120 | } |
150 | 121 | ||
151 | pub fn disabled() -> Filter { | 122 | fn install(mut self) { |
152 | Filter::new(0, Vec::new(), Duration::new(0, 0)) | 123 | PROFILING_ENABLED.store(self.depth > 0, Ordering::SeqCst); |
153 | } | 124 | let mut old = FILTER.write().unwrap(); |
154 | 125 | self.version = old.version + 1; | |
155 | pub fn new(depth: usize, allowed: Vec<String>, longer_than: Duration) -> Filter { | 126 | *old = self; |
156 | Filter { depth, allowed, longer_than } | ||
157 | } | 127 | } |
158 | } | 128 | } |
159 | 129 | ||
160 | struct ProfileStack { | 130 | struct ProfileStack { |
161 | starts: Vec<Instant>, | 131 | starts: Vec<Instant>, |
162 | messages: Vec<Message>, | 132 | messages: Vec<Message>, |
163 | filter_data: FilterData, | 133 | filter: Filter, |
164 | } | 134 | } |
165 | 135 | ||
166 | struct Message { | 136 | struct Message { |
@@ -172,45 +142,54 @@ struct Message { | |||
172 | 142 | ||
173 | impl ProfileStack { | 143 | impl ProfileStack { |
174 | fn new() -> ProfileStack { | 144 | fn new() -> ProfileStack { |
175 | ProfileStack { starts: Vec::new(), messages: Vec::new(), filter_data: Default::default() } | 145 | ProfileStack { starts: Vec::new(), messages: Vec::new(), filter: Default::default() } |
176 | } | 146 | } |
177 | } | ||
178 | 147 | ||
179 | #[derive(Default, Clone)] | 148 | fn push(&mut self, label: Label) -> bool { |
180 | struct FilterData { | 149 | if self.starts.is_empty() { |
181 | depth: usize, | 150 | if let Ok(f) = FILTER.try_read() { |
182 | version: usize, | 151 | if f.version > self.filter.version { |
183 | allowed: HashSet<String>, | 152 | self.filter = f.clone(); |
184 | longer_than: Duration, | 153 | } |
185 | } | 154 | }; |
186 | 155 | } | |
187 | static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false); | 156 | if self.starts.len() > self.filter.depth { |
157 | return false; | ||
158 | } | ||
159 | let allowed = &self.filter.allowed; | ||
160 | if self.starts.is_empty() && !allowed.is_empty() && !allowed.contains(label) { | ||
161 | return false; | ||
162 | } | ||
188 | 163 | ||
189 | static FILTER: Lazy<RwLock<FilterData>> = Lazy::new(Default::default); | 164 | self.starts.push(Instant::now()); |
165 | true | ||
166 | } | ||
190 | 167 | ||
191 | thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new())); | 168 | pub fn pop(&mut self, label: Label, detail: Option<String>) { |
169 | let start = self.starts.pop().unwrap(); | ||
170 | let duration = start.elapsed(); | ||
171 | let level = self.starts.len(); | ||
172 | self.messages.push(Message { level, duration, label, detail }); | ||
173 | if level == 0 { | ||
174 | let stdout = stderr(); | ||
175 | let longer_than = self.filter.longer_than; | ||
176 | // Convert to millis for comparison to avoid problems with rounding | ||
177 | // (otherwise we could print `0ms` despite user's `>0` filter when | ||
178 | // `duration` is just a few nanos). | ||
179 | if duration.as_millis() > longer_than.as_millis() { | ||
180 | print(&self.messages, longer_than, &mut stdout.lock()); | ||
181 | } | ||
182 | self.messages.clear(); | ||
183 | } | ||
184 | } | ||
185 | } | ||
192 | 186 | ||
193 | impl Drop for Profiler { | 187 | impl Drop for Profiler { |
194 | fn drop(&mut self) { | 188 | fn drop(&mut self) { |
195 | match self { | 189 | match self { |
196 | Profiler { label: Some(label), detail } => { | 190 | Profiler { label: Some(label), detail } => { |
197 | PROFILE_STACK.with(|stack| { | 191 | PROFILE_STACK.with(|stack| { |
198 | let mut stack = stack.borrow_mut(); | 192 | stack.borrow_mut().pop(label, detail.take()); |
199 | let start = stack.starts.pop().unwrap(); | ||
200 | let duration = start.elapsed(); | ||
201 | let level = stack.starts.len(); | ||
202 | stack.messages.push(Message { level, duration, label, detail: detail.take() }); | ||
203 | if level == 0 { | ||
204 | let stdout = stderr(); | ||
205 | let longer_than = stack.filter_data.longer_than; | ||
206 | // Convert to millis for comparison to avoid problems with rounding | ||
207 | // (otherwise we could print `0ms` despite user's `>0` filter when | ||
208 | // `duration` is just a few nanos). | ||
209 | if duration.as_millis() > longer_than.as_millis() { | ||
210 | print(&stack.messages, longer_than, &mut stdout.lock()); | ||
211 | } | ||
212 | stack.messages.clear(); | ||
213 | } | ||
214 | }); | 193 | }); |
215 | } | 194 | } |
216 | Profiler { label: None, .. } => (), | 195 | Profiler { label: None, .. } => (), |