aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--Cargo.lock1
-rw-r--r--crates/ra_prof/Cargo.toml1
-rw-r--r--crates/ra_prof/src/lib.rs35
3 files changed, 29 insertions, 8 deletions
diff --git a/Cargo.lock b/Cargo.lock
index 8dd894802..5aa4ff5de 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -1211,6 +1211,7 @@ dependencies = [
1211name = "ra_prof" 1211name = "ra_prof"
1212version = "0.1.0" 1212version = "0.1.0"
1213dependencies = [ 1213dependencies = [
1214 "itertools 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)",
1214 "once_cell 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)", 1215 "once_cell 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)",
1215] 1216]
1216 1217
diff --git a/crates/ra_prof/Cargo.toml b/crates/ra_prof/Cargo.toml
index 5f23e865c..efcce3d65 100644
--- a/crates/ra_prof/Cargo.toml
+++ b/crates/ra_prof/Cargo.toml
@@ -7,3 +7,4 @@ publish = false
7 7
8[dependencies] 8[dependencies]
9once_cell = "0.2.0" 9once_cell = "0.2.0"
10itertools = "0.8.0"
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)]