From dc356ffef71ef8cc679c414542ae9efcdf88cf52 Mon Sep 17 00:00:00 2001 From: Marcus Klaas Date: Tue, 14 Nov 2017 14:42:48 +0100 Subject: [PATCH] Add rudimentary timing of parsing and formatting phases --- Cargo.lock | 67 ++++++++++++++++++++++++++++++++++++-------------- Cargo.toml | 1 + src/lib.rs | 19 ++++++++++++-- src/summary.rs | 67 ++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 134 insertions(+), 20 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 87d2529fe24c8..b1c986eba834b 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -36,8 +36,8 @@ source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ "error-chain 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)", "semver 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)", - "serde 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", - "serde_derive 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_derive 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", "serde_json 1.0.8 (registry+https://github.com/rust-lang/crates.io-index)", ] @@ -84,7 +84,7 @@ name = "env_logger" version = "0.4.3" source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ - "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)", "regex 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)", ] @@ -127,8 +127,19 @@ source = "registry+https://github.com/rust-lang/crates.io-index" [[package]] name = "log" -version = "0.3.8" +version = "0.3.9" source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "log 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "log" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "cfg-if 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)", +] [[package]] name = "memchr" @@ -148,6 +159,11 @@ name = "quote" version = "0.3.15" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "redox_syscall" +version = "0.1.32" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "regex" version = "0.2.3" @@ -181,12 +197,13 @@ dependencies = [ "getopts 0.2.15 (registry+https://github.com/rust-lang/crates.io-index)", "kernel32-sys 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)", "libc 0.2.34 (registry+https://github.com/rust-lang/crates.io-index)", - "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)", "regex 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)", - "serde 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", - "serde_derive 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_derive 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", "serde_json 1.0.8 (registry+https://github.com/rust-lang/crates.io-index)", "term 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", + "time 0.1.38 (registry+https://github.com/rust-lang/crates.io-index)", "toml 0.4.5 (registry+https://github.com/rust-lang/crates.io-index)", "unicode-segmentation 1.2.0 (registry+https://github.com/rust-lang/crates.io-index)", "winapi 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)", @@ -198,7 +215,7 @@ version = "0.8.0" source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ "semver-parser 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)", - "serde 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -208,22 +225,22 @@ source = "registry+https://github.com/rust-lang/crates.io-index" [[package]] name = "serde" -version = "1.0.24" +version = "1.0.25" source = "registry+https://github.com/rust-lang/crates.io-index" [[package]] name = "serde_derive" -version = "1.0.24" +version = "1.0.25" source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ "quote 0.3.15 (registry+https://github.com/rust-lang/crates.io-index)", - "serde_derive_internals 0.18.0 (registry+https://github.com/rust-lang/crates.io-index)", + "serde_derive_internals 0.18.1 (registry+https://github.com/rust-lang/crates.io-index)", "syn 0.11.11 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] name = "serde_derive_internals" -version = "0.18.0" +version = "0.18.1" source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ "syn 0.11.11 (registry+https://github.com/rust-lang/crates.io-index)", @@ -238,7 +255,7 @@ dependencies = [ "dtoa 0.4.2 (registry+https://github.com/rust-lang/crates.io-index)", "itoa 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", "num-traits 0.1.41 (registry+https://github.com/rust-lang/crates.io-index)", - "serde 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -277,12 +294,23 @@ dependencies = [ "unreachable 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "time" +version = "0.1.38" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "kernel32-sys 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)", + "libc 0.2.34 (registry+https://github.com/rust-lang/crates.io-index)", + "redox_syscall 0.1.32 (registry+https://github.com/rust-lang/crates.io-index)", + "winapi 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "toml" version = "0.4.5" source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ - "serde 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)", + "serde 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -341,23 +369,26 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum kernel32-sys 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)" = "7507624b29483431c0ba2d82aece8ca6cdba9382bff4ddd0f7490560c056098d" "checksum lazy_static 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)" = "c8f31047daa365f19be14b47c29df4f7c3b581832407daabe6ae77397619237d" "checksum libc 0.2.34 (registry+https://github.com/rust-lang/crates.io-index)" = "36fbc8a8929c632868295d0178dd8f63fc423fd7537ad0738372bd010b3ac9b0" -"checksum log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)" = "880f77541efa6e5cc74e76910c9884d9859683118839d6a1dc3b11e63512565b" +"checksum log 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)" = "e19e8d5c34a3e0e2223db8e060f9e8264aeeb5c5fc64a4ee9965c062211c024b" +"checksum log 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "b3a89a0c46ba789b8a247d4c567aed4d7c68e624672d238b45cc3ec20dc9f940" "checksum memchr 2.0.1 (registry+https://github.com/rust-lang/crates.io-index)" = "796fba70e76612589ed2ce7f45282f5af869e0fdd7cc6199fa1aa1f1d591ba9d" "checksum num-traits 0.1.41 (registry+https://github.com/rust-lang/crates.io-index)" = "cacfcab5eb48250ee7d0c7896b51a2c5eec99c1feea5f32025635f5ae4b00070" "checksum quote 0.3.15 (registry+https://github.com/rust-lang/crates.io-index)" = "7a6e920b65c65f10b2ae65c831a81a073a89edd28c7cce89475bff467ab4167a" +"checksum redox_syscall 0.1.32 (registry+https://github.com/rust-lang/crates.io-index)" = "ab105df655884ede59d45b7070c8a65002d921461ee813a024558ca16030eea0" "checksum regex 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)" = "ac6ab4e9218ade5b423358bbd2567d1617418403c7a512603630181813316322" "checksum regex-syntax 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)" = "ad890a5eef7953f55427c50575c680c42841653abd2b028b68cd223d157f62db" "checksum rustc-demangle 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)" = "aee45432acc62f7b9a108cc054142dac51f979e69e71ddce7d6fc7adf29e817e" "checksum semver 0.8.0 (registry+https://github.com/rust-lang/crates.io-index)" = "bee2bc909ab2d8d60dab26e8cad85b25d795b14603a0dcb627b78b9d30b6454b" "checksum semver-parser 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)" = "388a1df253eca08550bef6c72392cfe7c30914bf41df5269b68cbd6ff8f570a3" -"checksum serde 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)" = "1c57ab4ec5fa85d08aaf8ed9245899d9bbdd66768945b21113b84d5f595cb6a1" -"checksum serde_derive 1.0.24 (registry+https://github.com/rust-lang/crates.io-index)" = "02c92ea07b6e49b959c1481804ebc9bfd92d3c459f1274c9a9546829e42a66ce" -"checksum serde_derive_internals 0.18.0 (registry+https://github.com/rust-lang/crates.io-index)" = "75c6aac7b99801a16db5b40b7bf0d7e4ba16e76fbf231e32a4677f271cac0603" +"checksum serde 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)" = "386122ba68c214599c44587e0c0b411e8d90894503a95425b4f9508e4317901f" +"checksum serde_derive 1.0.25 (registry+https://github.com/rust-lang/crates.io-index)" = "ec0bfa6c5784e7d110514448da0e1dbad41ea5514c3e68be755b23858b83a399" +"checksum serde_derive_internals 0.18.1 (registry+https://github.com/rust-lang/crates.io-index)" = "730fe9f29fe8db69a601837f416e46cba07792031ed6b27557a43e49d62d89ae" "checksum serde_json 1.0.8 (registry+https://github.com/rust-lang/crates.io-index)" = "7cf5b0b5b4bd22eeecb7e01ac2e1225c7ef5e4272b79ee28a8392a8c8489c839" "checksum syn 0.11.11 (registry+https://github.com/rust-lang/crates.io-index)" = "d3b891b9015c88c576343b9b3e41c2c11a51c219ef067b264bd9c8aa9b441dad" "checksum synom 0.11.3 (registry+https://github.com/rust-lang/crates.io-index)" = "a393066ed9010ebaed60b9eafa373d4b1baac186dd7e008555b0f702b51945b6" "checksum term 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)" = "fa63644f74ce96fbeb9b794f66aff2a52d601cbd5e80f4b97123e3899f4570f1" "checksum thread_local 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)" = "279ef31c19ededf577bfd12dfae728040a21f635b06a24cd670ff510edd38963" +"checksum time 0.1.38 (registry+https://github.com/rust-lang/crates.io-index)" = "d5d788d3aa77bc0ef3e9621256885555368b47bd495c13dd2e7413c89f845520" "checksum toml 0.4.5 (registry+https://github.com/rust-lang/crates.io-index)" = "a7540f4ffc193e0d3c94121edb19b055670d369f77d5804db11ae053a45b6e7e" "checksum unicode-segmentation 1.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "a8083c594e02b8ae1654ae26f0ade5158b119bd88ad0e8227a5d8fcd72407946" "checksum unicode-xid 0.0.4 (registry+https://github.com/rust-lang/crates.io-index)" = "8c1f860d7d29cf02cb2f3f359fd35991af3d30bac52c57d265a3c461074cb4dc" diff --git a/Cargo.toml b/Cargo.toml index a0f974c661443..5fd98c005e383 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -44,6 +44,7 @@ env_logger = "0.4" getopts = "0.2" derive-new = "0.5" cargo_metadata = "0.4" +time = "0.1" [target.'cfg(unix)'.dependencies] libc = "0.2.11" diff --git a/src/lib.rs b/src/lib.rs index d221f6a7d6049..c371d81efad38 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -23,6 +23,7 @@ extern crate serde_derive; extern crate serde_json; extern crate syntax; extern crate term; +extern crate time; extern crate unicode_segmentation; use std::collections::HashMap; @@ -616,6 +617,8 @@ pub fn format_input( } }; + summary.mark_parse_time(); + if parse_session.span_diagnostic.has_errors() { summary.add_parsing_error(); } @@ -630,7 +633,7 @@ pub fn format_input( let mut report = FormatReport::new(); - match format_ast( + let format_result = format_ast( &krate, &mut parse_session, &main_file, @@ -647,7 +650,19 @@ pub fn format_input( } Ok(false) }, - ) { + ); + + summary.mark_format_time(); + + if config.verbose() { + println!( + "Spent {} in the parsing phase, and {} in the formatting phase", + summary.get_parse_time().unwrap(), + summary.get_format_time().unwrap(), + ); + } + + match format_result { Ok((file_map, has_diff)) => { if report.has_warnings() { summary.add_formatting_error(); diff --git a/src/summary.rs b/src/summary.rs index 73ee80dac8513..33260d8c91ec2 100644 --- a/src/summary.rs +++ b/src/summary.rs @@ -1,3 +1,6 @@ +use time::{precise_time_ns, Duration}; +use std::default::Default; + #[must_use] #[derive(Debug, Default, Clone, Copy)] pub struct Summary { @@ -12,9 +15,42 @@ pub struct Summary { // Formatted code differs from existing code (write-mode diff only). pub has_diff: bool, + + // Keeps track of time spent in parsing and formatting steps. + timer: Timer, } impl Summary { + pub fn mark_parse_time(&mut self) { + self.timer = self.timer.done_parsing(); + } + + pub fn mark_format_time(&mut self) { + self.timer = self.timer.done_formatting(); + } + + /// Returns the time it took to parse the source files in nanoseconds. + pub fn get_parse_time(&self) -> Option { + match self.timer { + Timer::DoneParsing(init, parse_time) | Timer::DoneFormatting(init, parse_time, _) => { + // This should never underflow since `precise_time_ns()` guarantees monotonicity. + Some(Duration::nanoseconds((parse_time - init) as i64)) + } + Timer::Initialized(..) => None, + } + } + + /// Returns the time it took to go from the parsed AST to the formatted output. Parsing time is + /// not included. + pub fn get_format_time(&self) -> Option { + match self.timer { + Timer::DoneFormatting(_init, parse_time, format_time) => { + Some(Duration::nanoseconds((format_time - parse_time) as i64)) + } + Timer::DoneParsing(..) | Timer::Initialized(..) => None, + } + } + pub fn has_operational_errors(&self) -> bool { self.has_operational_errors } @@ -65,3 +101,34 @@ impl Summary { println!("{}", exit_codes); } } + +#[derive(Clone, Copy, Debug)] +enum Timer { + Initialized(u64), + DoneParsing(u64, u64), + DoneFormatting(u64, u64, u64), +} + +impl Default for Timer { + fn default() -> Self { + Timer::Initialized(precise_time_ns()) + } +} + +impl Timer { + fn done_parsing(self) -> Self { + match self { + Timer::Initialized(init_time) => Timer::DoneParsing(init_time, precise_time_ns()), + _ => panic!("Timer can only transition to DoneParsing from Initialized state"), + } + } + + fn done_formatting(self) -> Self { + match self { + Timer::DoneParsing(init_time, parse_time) => { + Timer::DoneFormatting(init_time, parse_time, precise_time_ns()) + } + _ => panic!("Timer can only transition to DoneFormatting from DoneParsing state"), + } + } +}