From 5b7012318cdf5fb0bb8b01319270c1b4bf0311ee Mon Sep 17 00:00:00 2001 From: Aleksey Kladov Date: Sun, 14 Apr 2019 23:18:58 +0300 Subject: filter by time --- crates/ra_lsp_server/src/main.rs | 25 ++++--------------------- crates/ra_prof/src/lib.rs | 40 +++++++++++++++++++++++++++++++++++----- docs/dev/README.md | 6 ++++-- 3 files changed, 43 insertions(+), 28 deletions(-) diff --git a/crates/ra_lsp_server/src/main.rs b/crates/ra_lsp_server/src/main.rs index 28f9985b6..b0b70df5c 100644 --- a/crates/ra_lsp_server/src/main.rs +++ b/crates/ra_lsp_server/src/main.rs @@ -8,31 +8,14 @@ use ra_prof; fn main() -> Result<()> { std::env::set_var("RUST_BACKTRACE", "short"); let logger = Logger::with_env_or_str("error").duplicate_to_stderr(Duplicate::All); - match std::env::var("RA_INTERNAL_MODE") { + match std::env::var("RA_LOG_DIR") { Ok(ref v) if v == "1" => logger.log_to_file().directory("log").start()?, _ => logger.start()?, }; - // Filtering syntax - // env RA_PROFILE=* // dump everything - // env RA_PROFILE=foo|bar|baz // enabled only selected entries - // env RA_PROFILE=*@3 // dump everything, up to depth 3 - let filter = match std::env::var("RA_PROFILE") { - Ok(p) => { - let mut p = p.as_str(); - let depth = if let Some(idx) = p.rfind("@") { - let depth: usize = p[idx + 1..].parse().expect("invalid profile depth"); - p = &p[..idx]; - depth - } else { - 999 - }; - let allowed = - if p == "*" { Vec::new() } else { p.split(";").map(String::from).collect() }; - ra_prof::Filter::new(depth, allowed) - } + ra_prof::set_filter(match std::env::var("RA_PROFILE") { + Ok(spec) => ra_prof::Filter::from_spec(&spec), Err(_) => ra_prof::Filter::disabled(), - }; - ra_prof::set_filter(filter); + }); log::info!("lifecycle: server started"); match ::std::panic::catch_unwind(main_inner) { Ok(res) => { diff --git a/crates/ra_prof/src/lib.rs b/crates/ra_prof/src/lib.rs index c7c21b6d2..999cc61f0 100644 --- a/crates/ra_prof/src/lib.rs +++ b/crates/ra_prof/src/lib.rs @@ -27,7 +27,8 @@ pub fn set_filter(f: Filter) { PROFILING_ENABLED.store(f.depth > 0, Ordering::SeqCst); let set = HashSet::from_iter(f.allowed.iter().cloned()); let mut old = FILTER.write().unwrap(); - let filter_data = FilterData { depth: f.depth, allowed: set, version: old.version + 1 }; + let filter_data = + FilterData { depth: f.depth, allowed: set, cutoff: f.cutoff, version: old.version + 1 }; *old = filter_data; } @@ -101,15 +102,41 @@ pub struct Profiler { pub struct Filter { depth: usize, allowed: Vec, + cutoff: Duration, } impl Filter { + // Filtering syntax + // env RA_PROFILE=* // dump everything + // env RA_PROFILE=foo|bar|baz // enabled only selected entries + // env RA_PROFILE=*@3>10 // dump everything, up to depth 3, if it takes more than 10 ms + pub fn from_spec(mut spec: &str) -> Filter { + let cutoff = if let Some(idx) = spec.rfind(">") { + let cutoff = spec[idx + 1..].parse().expect("invalid profile cutoff"); + spec = &spec[..idx]; + Duration::from_millis(cutoff) + } else { + Duration::new(0, 0) + }; + + let depth = if let Some(idx) = spec.rfind("@") { + let depth: usize = spec[idx + 1..].parse().expect("invalid profile depth"); + spec = &spec[..idx]; + depth + } else { + 999 + }; + let allowed = + if spec == "*" { Vec::new() } else { spec.split("|").map(String::from).collect() }; + Filter::new(depth, allowed, cutoff) + } + pub fn disabled() -> Filter { - Filter::new(0, Vec::new()) + Filter::new(0, Vec::new(), Duration::new(0, 0)) } - pub fn new(depth: usize, allowed: Vec) -> Filter { - Filter { depth, allowed } + pub fn new(depth: usize, allowed: Vec, cutoff: Duration) -> Filter { + Filter { depth, allowed, cutoff } } } @@ -136,6 +163,7 @@ struct FilterData { depth: usize, version: usize, allowed: HashSet, + cutoff: Duration, } static PROFILING_ENABLED: AtomicBool = AtomicBool::new(false); @@ -159,7 +187,9 @@ impl Drop for Profiler { stack.messages.push(Message { level, duration, message }); if level == 0 { let stdout = stderr(); - print(0, &stack.messages, &mut stdout.lock()); + if duration >= stack.filter_data.cutoff { + print(0, &stack.messages, &mut stdout.lock()); + } stack.messages.clear(); } }); diff --git a/docs/dev/README.md b/docs/dev/README.md index 7fb5886c9..d34ff96c8 100644 --- a/docs/dev/README.md +++ b/docs/dev/README.md @@ -105,7 +105,7 @@ figure out where logs go. Inside rust-analyzer, we use the standard `log` crate for logging, and `flexi_logger` for logging frotend. By default, log goes to stderr (the same as with `env_logger`), but the stderr itself is processed by VS Code. To mirror -logs to a `./log` directory, set `RA_INTERNAL_MODE=1` environmental variable. +logs to a `./log` directory, set `RA_LOG_DIR=1` environmental variable. To see stderr in the running VS Code instance, go to the "Output" tab of the panel and select `rust-analyzer`. This shows `eprintln!` as well. Note that @@ -143,5 +143,7 @@ We have a built-in hierarchical profiler, you can enable it by using `RA_PROF` e ``` RA_PROFILE=* // dump everything RA_PROFILE=foo|bar|baz // enabled only selected entries -RA_PROFILE=*@3 // dump everything, up to depth 3 +RA_PROFILE=*@3>10 // dump everything, up to depth 3, if it takes more than 10 ms ``` + +In particular, I have `export RA_PROFILE='*>10' in my shell profile. -- cgit v1.2.3