aboutsummaryrefslogtreecommitdiff
path: root/crates/ra_prof
diff options
context:
space:
mode:
Diffstat (limited to 'crates/ra_prof')
-rw-r--r--crates/ra_prof/src/lib.rs29
1 files changed, 25 insertions, 4 deletions
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
index f260c40a3..6dde304b1 100644
--- a/crates/ra_prof/src/lib.rs
+++ b/crates/ra_prof/src/lib.rs
@@ -197,7 +197,10 @@ impl Drop for Profiler {
197 if level == 0 { 197 if level == 0 {
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 // Convert to millis for comparison to avoid problems with rounding
201 // (otherwise we could print `0ms` despite user's `>0` filter when
202 // `duration` is just a few nanos).
203 if duration.as_millis() > longer_than.as_millis() {
201 print(0, &stack.messages, &mut stdout.lock(), longer_than, None); 204 print(0, &stack.messages, &mut stdout.lock(), longer_than, None);
202 } 205 }
203 stack.messages.clear(); 206 stack.messages.clear();
@@ -226,7 +229,7 @@ fn print(
226 continue; 229 continue;
227 } 230 }
228 accounted_for += duration; 231 accounted_for += duration;
229 if duration >= longer_than { 232 if duration.as_millis() > longer_than.as_millis() {
230 writeln!(out, "{}{:5}ms - {}", indent, duration.as_millis(), msg) 233 writeln!(out, "{}{:5}ms - {}", indent, duration.as_millis(), msg)
231 .expect("printing profiling info to stdout"); 234 .expect("printing profiling info to stdout");
232 235
@@ -251,8 +254,9 @@ fn print(
251 254
252 if let Some(total) = total { 255 if let Some(total) = total {
253 if let Some(unaccounted) = total.checked_sub(accounted_for) { 256 if let Some(unaccounted) = total.checked_sub(accounted_for) {
254 if unaccounted >= longer_than && last > 0 { 257 let unaccounted_millis = unaccounted.as_millis();
255 writeln!(out, "{}{:5}ms - ???", indent, unaccounted.as_millis()) 258 if unaccounted_millis > longer_than.as_millis() && unaccounted_millis > 0 && last > 0 {
259 writeln!(out, "{}{:5}ms - ???", indent, unaccounted_millis)
256 .expect("printing profiling info to stdout"); 260 .expect("printing profiling info to stdout");
257 } 261 }
258 } 262 }
@@ -356,4 +360,21 @@ mod tests {
356 fn profiling_function2() { 360 fn profiling_function2() {
357 let _p = profile("profile2"); 361 let _p = profile("profile2");
358 } 362 }
363
364 #[test]
365 fn test_longer_than() {
366 let mut result = vec![];
367 let msgs = vec![
368 Message { level: 1, duration: Duration::from_nanos(3), message: "bar".to_owned() },
369 Message { level: 1, duration: Duration::from_nanos(2), message: "bar".to_owned() },
370 Message { level: 0, duration: Duration::from_millis(1), message: "foo".to_owned() },
371 ];
372 print(0, &msgs, &mut result, Duration::from_millis(0), Some(Duration::from_millis(1)));
373 // The calls to `bar` are so short that they'll be rounded to 0ms and should get collapsed
374 // when printing.
375 assert_eq!(
376 std::str::from_utf8(&result).unwrap(),
377 " 1ms - foo\n 0ms - bar (2 calls)\n"
378 );
379 }
359} 380}