aboutsummaryrefslogtreecommitdiff
path: root/crates/ra_prof/src
diff options
context:
space:
mode:
authorAleksey Kladov <[email protected]>2019-10-24 07:05:11 +0100
committerAleksey Kladov <[email protected]>2019-10-24 07:14:33 +0100
commitbaa968e71cd09c4e9ca4bacbfdbdfa5abe6363a3 (patch)
tree2079abe97a89feaa06c7a56ffa9fdeba52e6bd97 /crates/ra_prof/src
parent2197205885f43441f14861f34449426295397dd9 (diff)
show unaccounted for time in profiling
Diffstat (limited to 'crates/ra_prof/src')
-rw-r--r--crates/ra_prof/src/lib.rs23
1 files changed, 20 insertions, 3 deletions
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
index 885a98750..e5385f51b 100644
--- a/crates/ra_prof/src/lib.rs
+++ b/crates/ra_prof/src/lib.rs
@@ -198,7 +198,7 @@ impl Drop for Profiler {
198 let stdout = stderr(); 198 let stdout = stderr();
199 let longer_than = stack.filter_data.longer_than; 199 let longer_than = stack.filter_data.longer_than;
200 if duration >= longer_than { 200 if duration >= longer_than {
201 print(0, &stack.messages, &mut stdout.lock(), longer_than); 201 print(0, &stack.messages, &mut stdout.lock(), longer_than, None);
202 } 202 }
203 stack.messages.clear(); 203 stack.messages.clear();
204 } 204 }
@@ -209,20 +209,28 @@ impl Drop for Profiler {
209 } 209 }
210} 210}
211 211
212fn print(lvl: usize, msgs: &[Message], out: &mut impl Write, longer_than: Duration) { 212fn print(
213 lvl: usize,
214 msgs: &[Message],
215 out: &mut impl Write,
216 longer_than: Duration,
217 total: Option<Duration>,
218) {
213 let mut last = 0; 219 let mut last = 0;
214 let indent = repeat(" ").take(lvl + 1).collect::<String>(); 220 let indent = repeat(" ").take(lvl + 1).collect::<String>();
215 // We output hierarchy for long calls, but sum up all short calls 221 // We output hierarchy for long calls, but sum up all short calls
216 let mut short = Vec::new(); 222 let mut short = Vec::new();
223 let mut accounted_for = Duration::default();
217 for (i, &Message { level, duration, message: ref msg }) in msgs.iter().enumerate() { 224 for (i, &Message { level, duration, message: ref msg }) in msgs.iter().enumerate() {
218 if level != lvl { 225 if level != lvl {
219 continue; 226 continue;
220 } 227 }
228 accounted_for += duration;
221 if duration >= longer_than { 229 if duration >= longer_than {
222 writeln!(out, "{} {:6}ms - {}", indent, duration.as_millis(), msg) 230 writeln!(out, "{} {:6}ms - {}", indent, duration.as_millis(), msg)
223 .expect("printing profiling info to stdout"); 231 .expect("printing profiling info to stdout");
224 232
225 print(lvl + 1, &msgs[last..i], out, longer_than); 233 print(lvl + 1, &msgs[last..i], out, longer_than, Some(duration));
226 } else { 234 } else {
227 short.push((msg, duration)) 235 short.push((msg, duration))
228 } 236 }
@@ -240,6 +248,15 @@ fn print(lvl: usize, msgs: &[Message], out: &mut impl Write, longer_than: Durati
240 writeln!(out, "{} {:6}ms - {} ({} calls)", indent, total_duration.as_millis(), msg, count) 248 writeln!(out, "{} {:6}ms - {} ({} calls)", indent, total_duration.as_millis(), msg, count)
241 .expect("printing profiling info to stdout"); 249 .expect("printing profiling info to stdout");
242 } 250 }
251
252 if let Some(total) = total {
253 if let Some(unaccounted) = total.checked_sub(accounted_for) {
254 if unaccounted >= longer_than && last > 0 {
255 writeln!(out, "{} {:6}ms - ???", indent, unaccounted.as_millis())
256 .expect("printing profiling info to stdout");
257 }
258 }
259 }
243} 260}
244 261
245/// Prints backtrace to stderr, useful for debugging. 262/// Prints backtrace to stderr, useful for debugging.