aboutsummaryrefslogtreecommitdiff
path: root/crates/ra_prof/src
diff options
context:
space:
mode:
authorAleksey Kladov <[email protected]>2019-05-21 22:00:58 +0100
committerAleksey Kladov <[email protected]>2019-05-21 22:00:58 +0100
commit6fed943bd2a96893cc5c3e4d2033e8c253d25d45 (patch)
tree768cbfb703c0fb5259a10efc241f97246753aaec /crates/ra_prof/src
parent366ad6f03ba2296f09cb79ea139fa53a132fa651 (diff)
better profilig
Diffstat (limited to 'crates/ra_prof/src')
-rw-r--r--crates/ra_prof/src/lib.rs35
1 files changed, 27 insertions, 8 deletions
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
index 61f2226d7..031405879 100644
--- a/crates/ra_prof/src/lib.rs
+++ b/crates/ra_prof/src/lib.rs
@@ -9,6 +9,7 @@ use std::{
9}; 9};
10 10
11use once_cell::sync::Lazy; 11use once_cell::sync::Lazy;
12use itertools::Itertools;
12 13
13/// Set profiling filter. It specifies descriptions allowed to profile. 14/// Set profiling filter. It specifies descriptions allowed to profile.
14/// This is helpful when call stack has too many nested profiling scopes. 15/// This is helpful when call stack has too many nested profiling scopes.
@@ -179,8 +180,9 @@ impl Drop for Profiler {
179 stack.messages.push(Message { level, duration, message }); 180 stack.messages.push(Message { level, duration, message });
180 if level == 0 { 181 if level == 0 {
181 let stdout = stderr(); 182 let stdout = stderr();
182 if duration >= stack.filter_data.longer_than { 183 let longer_than = stack.filter_data.longer_than;
183 print(0, &stack.messages, &mut stdout.lock()); 184 if duration >= longer_than {
185 print(0, &stack.messages, &mut stdout.lock(), longer_than);
184 } 186 }
185 stack.messages.clear(); 187 stack.messages.clear();
186 } 188 }
@@ -191,20 +193,37 @@ impl Drop for Profiler {
191 } 193 }
192} 194}
193 195
194fn print(lvl: usize, msgs: &[Message], out: &mut impl Write) { 196fn print(lvl: usize, msgs: &[Message], out: &mut impl Write, longer_than: Duration) {
195 let mut last = 0; 197 let mut last = 0;
196 let indent = repeat(" ").take(lvl + 1).collect::<String>(); 198 let indent = repeat(" ").take(lvl + 1).collect::<String>();
197 for (i, &Message { level: l, duration: dur, message: ref msg }) in msgs.iter().enumerate() { 199 // We output hierarchy for long calls, but sum up all short calls
198 if l != lvl { 200 let mut short = Vec::new();
201 for (i, &Message { level, duration, message: ref msg }) in msgs.iter().enumerate() {
202 if level != lvl {
199 continue; 203 continue;
200 } 204 }
205 if duration >= longer_than {
206 writeln!(out, "{} {:6}ms - {}", indent, duration.as_millis(), msg)
207 .expect("printing profiling info to stdout");
201 208
202 writeln!(out, "{} {:6}ms - {}", indent, dur.as_millis(), msg) 209 print(lvl + 1, &msgs[last..i], out, longer_than);
203 .expect("printing profiling info to stdout"); 210 } else {
211 short.push((msg, duration))
212 }
204 213
205 print(lvl + 1, &msgs[last..i], out);
206 last = i; 214 last = i;
207 } 215 }
216 short.sort_by_key(|(msg, _time)| *msg);
217 for (msg, entires) in short.iter().group_by(|(msg, _time)| msg).into_iter() {
218 let mut count = 0;
219 let mut total_duration = Duration::default();
220 entires.for_each(|(_msg, time)| {
221 count += 1;
222 total_duration += *time;
223 });
224 writeln!(out, "{} {:6}ms - {} ({} calls)", indent, total_duration.as_millis(), msg, count)
225 .expect("printing profiling info to stdout");
226 }
208} 227}
209 228
210#[cfg(test)] 229#[cfg(test)]