aboutsummaryrefslogtreecommitdiff
path: root/crates
diff options
context:
space:
mode:
authorAleksey Kladov <[email protected]>2020-07-30 08:44:21 +0100
committerAleksey Kladov <[email protected]>2020-07-30 09:23:32 +0100
commit7204374719f4021ce06c25e7dd72b09a56923954 (patch)
tree2e589e4b57540a87ed46aa831a7ad1af6ab8ad40 /crates
parent4bab553029da31f3e90e99d8b83d160a34fdf4b2 (diff)
Report instructions in addition to time
They hopefully will be more stable on CI
Diffstat (limited to 'crates')
-rw-r--r--crates/ra_prof/Cargo.toml1
-rw-r--r--crates/ra_prof/src/lib.rs2
-rw-r--r--crates/ra_prof/src/stop_watch.rs72
-rw-r--r--crates/rust-analyzer/src/cli/analysis_stats.rs40
4 files changed, 95 insertions, 20 deletions
diff --git a/crates/ra_prof/Cargo.toml b/crates/ra_prof/Cargo.toml
index 6c214501e..e41cb5f52 100644
--- a/crates/ra_prof/Cargo.toml
+++ b/crates/ra_prof/Cargo.toml
@@ -15,6 +15,7 @@ once_cell = "1.3.1"
15backtrace = { version = "0.3.44", optional = true } 15backtrace = { version = "0.3.44", optional = true }
16cfg-if = "0.1.10" 16cfg-if = "0.1.10"
17libc = "0.2.73" 17libc = "0.2.73"
18perf-event = "0.4"
18 19
19[features] 20[features]
20cpu_profiler = [] 21cpu_profiler = []
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
index ba5609703..eb50965ae 100644
--- a/crates/ra_prof/src/lib.rs
+++ b/crates/ra_prof/src/lib.rs
@@ -1,5 +1,6 @@
1//! A collection of tools for profiling rust-analyzer. 1//! A collection of tools for profiling rust-analyzer.
2 2
3mod stop_watch;
3mod memory_usage; 4mod memory_usage;
4#[cfg(feature = "cpu_profiler")] 5#[cfg(feature = "cpu_profiler")]
5mod google_cpu_profiler; 6mod google_cpu_profiler;
@@ -11,6 +12,7 @@ use std::cell::RefCell;
11pub use crate::{ 12pub use crate::{
12 hprof::{init, init_from, profile}, 13 hprof::{init, init_from, profile},
13 memory_usage::{Bytes, MemoryUsage}, 14 memory_usage::{Bytes, MemoryUsage},
15 stop_watch::{StopWatch, StopWatchSpan},
14}; 16};
15 17
16/// Prints backtrace to stderr, useful for debugging. 18/// Prints backtrace to stderr, useful for debugging.
diff --git a/crates/ra_prof/src/stop_watch.rs b/crates/ra_prof/src/stop_watch.rs
new file mode 100644
index 000000000..54bfb0559
--- /dev/null
+++ b/crates/ra_prof/src/stop_watch.rs
@@ -0,0 +1,72 @@
1use crate::MemoryUsage;
2use std::{
3 fmt,
4 time::{Duration, Instant},
5};
6
7pub struct StopWatch {
8 time: Instant,
9 counter: Option<perf_event::Counter>,
10 memory: Option<MemoryUsage>,
11}
12
13pub struct StopWatchSpan {
14 pub time: Duration,
15 pub instructions: Option<u64>,
16 pub memory: Option<MemoryUsage>,
17}
18
19impl StopWatch {
20 pub fn start() -> StopWatch {
21 let mut counter = perf_event::Builder::new().build().ok();
22 if let Some(counter) = &mut counter {
23 let _ = counter.enable();
24 }
25 let time = Instant::now();
26 StopWatch { time, counter, memory: None }
27 }
28 pub fn memory(mut self, yes: bool) -> StopWatch {
29 if yes {
30 self.memory = Some(MemoryUsage::current());
31 }
32 self
33 }
34 pub fn elapsed(&mut self) -> StopWatchSpan {
35 let time = self.time.elapsed();
36 let instructions = self.counter.as_mut().and_then(|it| it.read().ok());
37 let memory = self.memory.map(|it| MemoryUsage::current() - it);
38 StopWatchSpan { time, instructions, memory }
39 }
40}
41
42impl fmt::Display for StopWatchSpan {
43 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
44 write!(f, "{:.2?}", self.time)?;
45 if let Some(mut instructions) = self.instructions {
46 let mut prefix = "";
47 if instructions > 10000 {
48 instructions /= 1000;
49 prefix = "k"
50 }
51 if instructions > 10000 {
52 instructions /= 1000;
53 prefix = "m"
54 }
55 write!(f, ", {}{}i", instructions, prefix)?;
56 }
57 if let Some(memory) = self.memory {
58 write!(f, ", {}", memory)?;
59 }
60 Ok(())
61 }
62}
63
64// Unclear if we need this:
65// https://github.com/jimblandy/perf-event/issues/8
66impl Drop for StopWatch {
67 fn drop(&mut self) {
68 if let Some(mut counter) = self.counter.take() {
69 let _ = counter.disable();
70 }
71 }
72}
diff --git a/crates/rust-analyzer/src/cli/analysis_stats.rs b/crates/rust-analyzer/src/cli/analysis_stats.rs
index cf0d82b62..37b8337ef 100644
--- a/crates/rust-analyzer/src/cli/analysis_stats.rs
+++ b/crates/rust-analyzer/src/cli/analysis_stats.rs
@@ -3,7 +3,7 @@
3 3
4use std::{ 4use std::{
5 path::Path, 5 path::Path,
6 time::{Instant, SystemTime, UNIX_EPOCH}, 6 time::{SystemTime, UNIX_EPOCH},
7}; 7};
8 8
9use hir::{ 9use hir::{
@@ -29,6 +29,7 @@ use crate::{
29 }, 29 },
30 print_memory_usage, 30 print_memory_usage,
31}; 31};
32use ra_prof::StopWatch;
32 33
33/// Need to wrap Snapshot to provide `Clone` impl for `map_with` 34/// Need to wrap Snapshot to provide `Clone` impl for `map_with`
34struct Snap<DB>(DB); 35struct Snap<DB>(DB);
@@ -54,11 +55,12 @@ pub fn analysis_stats(
54 Rand32::new(seed) 55 Rand32::new(seed)
55 }; 56 };
56 57
57 let db_load_time = Instant::now(); 58 let mut db_load_sw = StopWatch::start().memory(memory_usage);
58 let (host, vfs) = load_cargo(path, load_output_dirs, with_proc_macro)?; 59 let (host, vfs) = load_cargo(path, load_output_dirs, with_proc_macro)?;
59 let db = host.raw_database(); 60 let db = host.raw_database();
60 eprintln!("Database loaded {:?}", db_load_time.elapsed()); 61 eprintln!("Database loaded {}", db_load_sw.elapsed());
61 let analysis_time = Instant::now(); 62
63 let mut analysis_sw = StopWatch::start().memory(memory_usage);
62 let mut num_crates = 0; 64 let mut num_crates = 0;
63 let mut visited_modules = FxHashSet::default(); 65 let mut visited_modules = FxHashSet::default();
64 let mut visit_queue = Vec::new(); 66 let mut visit_queue = Vec::new();
@@ -110,8 +112,7 @@ pub fn analysis_stats(
110 eprintln!("Total modules found: {}", visited_modules.len()); 112 eprintln!("Total modules found: {}", visited_modules.len());
111 eprintln!("Total declarations: {}", num_decls); 113 eprintln!("Total declarations: {}", num_decls);
112 eprintln!("Total functions: {}", funcs.len()); 114 eprintln!("Total functions: {}", funcs.len());
113 let item_collection_memory = ra_prof::memory_usage(); 115 eprintln!("Item Collection: {}", analysis_sw.elapsed());
114 eprintln!("Item Collection: {:?}, {}", analysis_time.elapsed(), item_collection_memory);
115 116
116 if randomize { 117 if randomize {
117 shuffle(&mut rng, &mut funcs); 118 shuffle(&mut rng, &mut funcs);
@@ -123,7 +124,7 @@ pub fn analysis_stats(
123 }; 124 };
124 125
125 if parallel { 126 if parallel {
126 let inference_time = Instant::now(); 127 let mut inference_sw = StopWatch::start().memory(memory_usage);
127 let snap = Snap(db.snapshot()); 128 let snap = Snap(db.snapshot());
128 funcs 129 funcs
129 .par_iter() 130 .par_iter()
@@ -133,14 +134,10 @@ pub fn analysis_stats(
133 snap.0.infer(f_id.into()); 134 snap.0.infer(f_id.into());
134 }) 135 })
135 .count(); 136 .count();
136 eprintln!( 137 eprintln!("Parallel Inference: {}", inference_sw.elapsed());
137 "Parallel Inference: {:?}, {}",
138 inference_time.elapsed(),
139 ra_prof::memory_usage()
140 );
141 } 138 }
142 139
143 let inference_time = Instant::now(); 140 let mut inference_sw = StopWatch::start().memory(memory_usage);
144 bar.tick(); 141 bar.tick();
145 let mut num_exprs = 0; 142 let mut num_exprs = 0;
146 let mut num_exprs_unknown = 0; 143 let mut num_exprs_unknown = 0;
@@ -291,14 +288,17 @@ pub fn analysis_stats(
291 eprintln!("Type mismatches: {}", num_type_mismatches); 288 eprintln!("Type mismatches: {}", num_type_mismatches);
292 report_metric("type mismatches", num_type_mismatches, "#"); 289 report_metric("type mismatches", num_type_mismatches, "#");
293 290
294 let inference_time = inference_time.elapsed(); 291 eprintln!("Inference: {}", inference_sw.elapsed());
295 let total_memory = ra_prof::memory_usage();
296 eprintln!("Inference: {:?}, {}", inference_time, total_memory - item_collection_memory);
297 292
298 let analysis_time = analysis_time.elapsed(); 293 let total_span = analysis_sw.elapsed();
299 eprintln!("Total: {:?}, {}", analysis_time, total_memory); 294 eprintln!("Total: {}", total_span);
300 report_metric("total time", analysis_time.as_millis() as u64, "ms"); 295 report_metric("total time", total_span.time.as_millis() as u64, "ms");
301 report_metric("total memory", total_memory.allocated.megabytes() as u64, "MB"); 296 if let Some(instructions) = total_span.instructions {
297 report_metric("total time", instructions, "#instr");
298 }
299 if let Some(memory) = total_span.memory {
300 report_metric("total memory", memory.allocated.megabytes() as u64, "MB");
301 }
302 302
303 if memory_usage { 303 if memory_usage {
304 print_memory_usage(host, vfs); 304 print_memory_usage(host, vfs);