aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--Cargo.lock10
-rw-r--r--crates/ra_cli/Cargo.toml1
-rw-r--r--crates/ra_cli/src/main.rs7
-rw-r--r--crates/ra_hir/Cargo.toml1
-rw-r--r--crates/ra_hir/src/nameres.rs4
-rw-r--r--crates/ra_lsp_server/Cargo.toml1
-rw-r--r--crates/ra_lsp_server/src/main.rs10
-rw-r--r--crates/ra_lsp_server/src/main_loop.rs7
-rw-r--r--crates/ra_prof/Cargo.toml9
-rw-r--r--crates/ra_prof/src/lib.rs153
10 files changed, 193 insertions, 10 deletions
diff --git a/Cargo.lock b/Cargo.lock
index ddd508b0a..06117ceaf 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -931,6 +931,7 @@ dependencies = [
931 "ra_db 0.1.0", 931 "ra_db 0.1.0",
932 "ra_hir 0.1.0", 932 "ra_hir 0.1.0",
933 "ra_ide_api 0.1.0", 933 "ra_ide_api 0.1.0",
934 "ra_prof 0.1.0",
934 "ra_syntax 0.1.0", 935 "ra_syntax 0.1.0",
935 "tools 0.1.0", 936 "tools 0.1.0",
936] 937]
@@ -970,6 +971,7 @@ dependencies = [
970 "ra_arena 0.1.0", 971 "ra_arena 0.1.0",
971 "ra_db 0.1.0", 972 "ra_db 0.1.0",
972 "ra_mbe 0.1.0", 973 "ra_mbe 0.1.0",
974 "ra_prof 0.1.0",
973 "ra_syntax 0.1.0", 975 "ra_syntax 0.1.0",
974 "ra_tt 0.1.0", 976 "ra_tt 0.1.0",
975 "relative-path 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)", 977 "relative-path 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -1018,6 +1020,7 @@ dependencies = [
1018 "parking_lot 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)", 1020 "parking_lot 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)",
1019 "ra_arena 0.1.0", 1021 "ra_arena 0.1.0",
1020 "ra_ide_api 0.1.0", 1022 "ra_ide_api 0.1.0",
1023 "ra_prof 0.1.0",
1021 "ra_project_model 0.1.0", 1024 "ra_project_model 0.1.0",
1022 "ra_syntax 0.1.0", 1025 "ra_syntax 0.1.0",
1023 "ra_text_edit 0.1.0", 1026 "ra_text_edit 0.1.0",
@@ -1051,6 +1054,13 @@ dependencies = [
1051] 1054]
1052 1055
1053[[package]] 1056[[package]]
1057name = "ra_prof"
1058version = "0.1.0"
1059dependencies = [
1060 "lazy_static 1.3.0 (registry+https://github.com/rust-lang/crates.io-index)",
1061]
1062
1063[[package]]
1054name = "ra_project_model" 1064name = "ra_project_model"
1055version = "0.1.0" 1065version = "0.1.0"
1056dependencies = [ 1066dependencies = [
diff --git a/crates/ra_cli/Cargo.toml b/crates/ra_cli/Cargo.toml
index 467628236..328b2436f 100644
--- a/crates/ra_cli/Cargo.toml
+++ b/crates/ra_cli/Cargo.toml
@@ -18,3 +18,4 @@ tools = { path = "../tools" }
18ra_batch = { path = "../ra_batch" } 18ra_batch = { path = "../ra_batch" }
19ra_hir = { path = "../ra_hir" } 19ra_hir = { path = "../ra_hir" }
20ra_db = { path = "../ra_db" } 20ra_db = { path = "../ra_db" }
21ra_prof = { path = "../ra_prof" }
diff --git a/crates/ra_cli/src/main.rs b/crates/ra_cli/src/main.rs
index 1f2750d89..45555be6e 100644
--- a/crates/ra_cli/src/main.rs
+++ b/crates/ra_cli/src/main.rs
@@ -1,12 +1,13 @@
1mod analysis_stats; 1mod analysis_stats;
2 2
3use std::{fs, io::Read, path::Path, time::Instant}; 3use std::{fs, io::Read, path::Path};
4 4
5use clap::{App, Arg, SubCommand}; 5use clap::{App, Arg, SubCommand};
6use ra_ide_api::file_structure; 6use ra_ide_api::file_structure;
7use ra_syntax::{SourceFile, TreeArc, AstNode}; 7use ra_syntax::{SourceFile, TreeArc, AstNode};
8use tools::collect_tests; 8use tools::collect_tests;
9use flexi_logger::Logger; 9use flexi_logger::Logger;
10use ra_prof::profile;
10 11
11type Result<T> = ::std::result::Result<T, failure::Error>; 12type Result<T> = ::std::result::Result<T, failure::Error>;
12 13
@@ -27,13 +28,11 @@ fn main() -> Result<()> {
27 .get_matches(); 28 .get_matches();
28 match matches.subcommand() { 29 match matches.subcommand() {
29 ("parse", Some(matches)) => { 30 ("parse", Some(matches)) => {
30 let start = Instant::now(); 31 let _p = profile("parsing");
31 let file = file()?; 32 let file = file()?;
32 let elapsed = start.elapsed();
33 if !matches.is_present("no-dump") { 33 if !matches.is_present("no-dump") {
34 println!("{}", file.syntax().debug_dump()); 34 println!("{}", file.syntax().debug_dump());
35 } 35 }
36 eprintln!("parsing: {:?}", elapsed);
37 ::std::mem::forget(file); 36 ::std::mem::forget(file);
38 } 37 }
39 ("symbols", _) => { 38 ("symbols", _) => {
diff --git a/crates/ra_hir/Cargo.toml b/crates/ra_hir/Cargo.toml
index 501308acc..a2858dad9 100644
--- a/crates/ra_hir/Cargo.toml
+++ b/crates/ra_hir/Cargo.toml
@@ -19,6 +19,7 @@ ra_db = { path = "../ra_db" }
19mbe = { path = "../ra_mbe", package = "ra_mbe" } 19mbe = { path = "../ra_mbe", package = "ra_mbe" }
20tt = { path = "../ra_tt", package = "ra_tt" } 20tt = { path = "../ra_tt", package = "ra_tt" }
21test_utils = { path = "../test_utils" } 21test_utils = { path = "../test_utils" }
22ra_prof = {path = "../ra_prof" }
22 23
23[dev-dependencies] 24[dev-dependencies]
24flexi_logger = "0.11.0" 25flexi_logger = "0.11.0"
diff --git a/crates/ra_hir/src/nameres.rs b/crates/ra_hir/src/nameres.rs
index 6f049acfc..4ae04514a 100644
--- a/crates/ra_hir/src/nameres.rs
+++ b/crates/ra_hir/src/nameres.rs
@@ -60,6 +60,7 @@ use ra_arena::{Arena, RawId, impl_arena_id};
60use ra_db::{FileId, Edition}; 60use ra_db::{FileId, Edition};
61use test_utils::tested_by; 61use test_utils::tested_by;
62use ra_syntax::ast; 62use ra_syntax::ast;
63use ra_prof::profile;
63 64
64use crate::{ 65use crate::{
65 ModuleDef, Name, Crate, Module, 66 ModuleDef, Name, Crate, Module,
@@ -181,7 +182,7 @@ enum ReachedFixedPoint {
181 182
182impl CrateDefMap { 183impl CrateDefMap {
183 pub(crate) fn crate_def_map_query(db: &impl DefDatabase, krate: Crate) -> Arc<CrateDefMap> { 184 pub(crate) fn crate_def_map_query(db: &impl DefDatabase, krate: Crate) -> Arc<CrateDefMap> {
184 let start = std::time::Instant::now(); 185 let _p = profile("crate_def_map_query");
185 let def_map = { 186 let def_map = {
186 let edition = krate.edition(db); 187 let edition = krate.edition(db);
187 let mut modules: Arena<CrateModuleId, ModuleData> = Arena::default(); 188 let mut modules: Arena<CrateModuleId, ModuleData> = Arena::default();
@@ -198,7 +199,6 @@ impl CrateDefMap {
198 } 199 }
199 }; 200 };
200 let def_map = collector::collect_defs(db, def_map); 201 let def_map = collector::collect_defs(db, def_map);
201 log::info!("crate_def_map_query: {:?}", start.elapsed());
202 Arc::new(def_map) 202 Arc::new(def_map)
203 } 203 }
204 204
diff --git a/crates/ra_lsp_server/Cargo.toml b/crates/ra_lsp_server/Cargo.toml
index d82410700..bc181e4eb 100644
--- a/crates/ra_lsp_server/Cargo.toml
+++ b/crates/ra_lsp_server/Cargo.toml
@@ -27,6 +27,7 @@ ra_ide_api = { path = "../ra_ide_api" }
27ra_arena = { path = "../ra_arena" } 27ra_arena = { path = "../ra_arena" }
28gen_lsp_server = { path = "../gen_lsp_server" } 28gen_lsp_server = { path = "../gen_lsp_server" }
29ra_project_model = { path = "../ra_project_model" } 29ra_project_model = { path = "../ra_project_model" }
30ra_prof = { path = "../ra_prof" }
30 31
31[dev-dependencies] 32[dev-dependencies]
32tempfile = "3" 33tempfile = "3"
diff --git a/crates/ra_lsp_server/src/main.rs b/crates/ra_lsp_server/src/main.rs
index 5a2905207..eb4091a3d 100644
--- a/crates/ra_lsp_server/src/main.rs
+++ b/crates/ra_lsp_server/src/main.rs
@@ -3,6 +3,7 @@ use flexi_logger::{Duplicate, Logger};
3use gen_lsp_server::{run_server, stdio_transport}; 3use gen_lsp_server::{run_server, stdio_transport};
4 4
5use ra_lsp_server::{Result, InitializationOptions}; 5use ra_lsp_server::{Result, InitializationOptions};
6use ra_prof;
6 7
7fn main() -> Result<()> { 8fn main() -> Result<()> {
8 ::std::env::set_var("RUST_BACKTRACE", "short"); 9 ::std::env::set_var("RUST_BACKTRACE", "short");
@@ -11,6 +12,15 @@ fn main() -> Result<()> {
11 Ok(ref v) if v == "1" => logger.log_to_file().directory("log").start()?, 12 Ok(ref v) if v == "1" => logger.log_to_file().directory("log").start()?,
12 _ => logger.start()?, 13 _ => logger.start()?,
13 }; 14 };
15 let prof_depth = match ::std::env::var("RA_PROFILE_DEPTH") {
16 Ok(ref d) => d.parse()?,
17 _ => 0,
18 };
19 let profile_allowed = match ::std::env::var("RA_PROFILE") {
20 Ok(ref p) => p.split(";").map(String::from).collect(),
21 _ => Vec::new(),
22 };
23 ra_prof::set_filter(ra_prof::Filter::new(prof_depth, profile_allowed));
14 log::info!("lifecycle: server started"); 24 log::info!("lifecycle: server started");
15 match ::std::panic::catch_unwind(main_inner) { 25 match ::std::panic::catch_unwind(main_inner) {
16 Ok(res) => { 26 Ok(res) => {
diff --git a/crates/ra_lsp_server/src/main_loop.rs b/crates/ra_lsp_server/src/main_loop.rs
index eecf278a8..82410bee3 100644
--- a/crates/ra_lsp_server/src/main_loop.rs
+++ b/crates/ra_lsp_server/src/main_loop.rs
@@ -24,6 +24,7 @@ use crate::{
24 Result, 24 Result,
25 InitializationOptions, 25 InitializationOptions,
26}; 26};
27use ra_prof::profile;
27 28
28#[derive(Debug, Fail)] 29#[derive(Debug, Fail)]
29#[fail(display = "Language Server request failed with {}. ({})", code, message)] 30#[fail(display = "Language Server request failed with {}. ({})", code, message)]
@@ -181,7 +182,7 @@ fn main_loop_inner(
181 recv(libdata_receiver) -> data => Event::Lib(data.unwrap()) 182 recv(libdata_receiver) -> data => Event::Lib(data.unwrap())
182 }; 183 };
183 log::info!("loop_turn = {:?}", event); 184 log::info!("loop_turn = {:?}", event);
184 let start = std::time::Instant::now(); 185 let _p = profile("loop_turn");
185 let mut state_changed = false; 186 let mut state_changed = false;
186 match event { 187 match event {
187 Event::Task(task) => on_task(task, msg_sender, pending_requests), 188 Event::Task(task) => on_task(task, msg_sender, pending_requests),
@@ -235,10 +236,9 @@ fn main_loop_inner(
235 in_flight_libraries += 1; 236 in_flight_libraries += 1;
236 let sender = libdata_sender.clone(); 237 let sender = libdata_sender.clone();
237 pool.execute(move || { 238 pool.execute(move || {
238 let start = ::std::time::Instant::now();
239 log::info!("indexing {:?} ... ", root); 239 log::info!("indexing {:?} ... ", root);
240 let _p = profile(&format!("indexed {:?}", root));
240 let data = LibraryData::prepare(root, files); 241 let data = LibraryData::prepare(root, files);
241 log::info!("indexed {:?} {:?}", start.elapsed(), root);
242 sender.send(data).unwrap(); 242 sender.send(data).unwrap();
243 }); 243 });
244 } 244 }
@@ -266,7 +266,6 @@ fn main_loop_inner(
266 subs.subscriptions(), 266 subs.subscriptions(),
267 ) 267 )
268 } 268 }
269 log::info!("loop_turn = {:?}", start.elapsed());
270 } 269 }
271} 270}
272 271
diff --git a/crates/ra_prof/Cargo.toml b/crates/ra_prof/Cargo.toml
new file mode 100644
index 000000000..19ce21783
--- /dev/null
+++ b/crates/ra_prof/Cargo.toml
@@ -0,0 +1,9 @@
1[package]
2edition = "2018"
3name = "ra_prof"
4version = "0.1.0"
5authors = ["rust-analyzer developers"]
6publish = false
7
8[dependencies]
9lazy_static = "1.3.0" \ No newline at end of file
diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs
new file mode 100644
index 000000000..abddff960
--- /dev/null
+++ b/crates/ra_prof/src/lib.rs
@@ -0,0 +1,153 @@
1use std::cell::RefCell;
2use std::time::{Duration, Instant};
3use std::mem;
4use std::io::{stderr, Write};
5use std::iter::repeat;
6use std::collections::{HashSet};
7use std::default::Default;
8use std::iter::FromIterator;
9use std::sync::RwLock;
10use lazy_static::lazy_static;
11
12pub fn set_filter(f: Filter) {
13 let set = HashSet::from_iter(f.allowed.iter().cloned());
14 let mut old = FILTER.write().unwrap();
15 let filter_data = FilterData { depth: f.depth, allowed: set, version: old.version + 1 };
16 *old = filter_data;
17}
18
19pub fn profile(desc: &str) -> Profiler {
20 PROFILE_STACK.with(|stack| {
21 let mut stack = stack.borrow_mut();
22 if stack.starts.len() == 0 {
23 match FILTER.try_read() {
24 Ok(f) => {
25 if f.version > stack.filter_data.version {
26 stack.filter_data = f.clone();
27 }
28 }
29 Err(_) => (),
30 };
31 }
32 let desc_str = desc.to_string();
33 if desc_str.is_empty() {
34 Profiler { desc: None }
35 } else if stack.starts.len() < stack.filter_data.depth
36 && stack.filter_data.allowed.contains(&desc_str)
37 {
38 stack.starts.push(Instant::now());
39 Profiler { desc: Some(desc_str) }
40 } else {
41 Profiler { desc: None }
42 }
43 })
44}
45
46pub struct Profiler {
47 desc: Option<String>,
48}
49
50pub struct Filter {
51 depth: usize,
52 allowed: Vec<String>,
53}
54
55impl Filter {
56 pub fn new(depth: usize, allowed: Vec<String>) -> Filter {
57 Filter { depth, allowed }
58 }
59}
60
61struct ProfileStack {
62 starts: Vec<Instant>,
63 messages: Vec<Message>,
64 filter_data: FilterData,
65}
66
67struct Message {
68 level: usize,
69 duration: Duration,
70 message: String,
71}
72
73impl ProfileStack {
74 fn new() -> ProfileStack {
75 ProfileStack { starts: Vec::new(), messages: Vec::new(), filter_data: Default::default() }
76 }
77}
78
79#[derive(Default, Clone)]
80struct FilterData {
81 depth: usize,
82 version: usize,
83 allowed: HashSet<String>,
84}
85
86lazy_static! {
87 static ref FILTER: RwLock<FilterData> = RwLock::new(Default::default());
88}
89
90thread_local!(static PROFILE_STACK: RefCell<ProfileStack> = RefCell::new(ProfileStack::new()));
91
92impl Drop for Profiler {
93 fn drop(&mut self) {
94 match self {
95 Profiler { desc: Some(desc) } => {
96 PROFILE_STACK.with(|stack| {
97 let mut stack = stack.borrow_mut();
98 let start = stack.starts.pop().unwrap();
99 let duration = start.elapsed();
100 let level = stack.starts.len();
101 let message = mem::replace(desc, String::new());
102 stack.messages.push(Message { level, duration, message });
103 if level == 0 {
104 let stdout = stderr();
105 print(0, &stack.messages, &mut stdout.lock());
106 stack.messages.clear();
107 }
108 });
109 }
110 Profiler { desc: None } => (),
111 }
112 }
113}
114
115fn print(lvl: usize, msgs: &[Message], out: &mut impl Write) {
116 let mut last = 0;
117 let indent = repeat(" ").take(lvl + 1).collect::<String>();
118 for (i, &Message { level: l, duration: dur, message: ref msg }) in msgs.iter().enumerate() {
119 if l != lvl {
120 continue;
121 }
122 writeln!(out, "{} {:6}ms - {}", indent, dur.as_millis(), msg)
123 .expect("printing profiling info to stdout");
124
125 print(lvl + 1, &msgs[last..i], out);
126 last = i;
127 }
128}
129
130#[cfg(test)]
131mod tests {
132
133 use super::profile;
134 use super::set_filter;
135 use super::Filter;
136
137 #[test]
138 fn test_basic_profile() {
139 let s = vec!["profile1".to_string(), "profile2".to_string()];
140 let f = Filter { depth: 2, allowed: s };
141 set_filter(f);
142 profiling_function1();
143 }
144
145 fn profiling_function1() {
146 let _p = profile("profile1");
147 profiling_function2();
148 }
149
150 fn profiling_function2() {
151 let _p = profile("profile2");
152 }
153}