Skip to content

Add rudimentary timing of parsing and formatting phases #2149

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 2 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 19 additions & 0 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

23 changes: 21 additions & 2 deletions src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@ use std::io::{self, stdout, Write};
use std::iter::repeat;
use std::path::{Path, PathBuf};
use std::rc::Rc;
use std::time::Duration;

use errors::{DiagnosticBuilder, Handler};
use errors::emitter::{ColorConfig, EmitterWriter};
Expand Down Expand Up @@ -518,6 +519,8 @@ pub fn format_input<T: Write>(
}
};

summary.mark_parse_time();

if parse_session.span_diagnostic.has_errors() {
summary.add_parsing_error();
}
Expand All @@ -532,7 +535,7 @@ pub fn format_input<T: Write>(

let mut report = FormatReport::new();

match format_ast(
let format_result = format_ast(
&krate,
&mut parse_session,
&main_file,
Expand All @@ -549,7 +552,23 @@ pub fn format_input<T: Write>(
}
Ok(false)
},
) {
);

summary.mark_format_time();

if config.verbose() {
fn duration_to_f32(d: Duration) -> f32 {
d.as_secs() as f32 + d.subsec_nanos() as f32 / 1_000_000_000f32
}

println!(
"Spent {0:.3} secs in the parsing phase, and {1:.3} secs in the formatting phase",
duration_to_f32(summary.get_parse_time().unwrap()),
duration_to_f32(summary.get_format_time().unwrap()),
);
}

match format_result {
Ok((file_map, has_diff)) => {
if report.has_warnings() {
summary.add_formatting_error();
Expand Down
67 changes: 67 additions & 0 deletions src/summary.rs
Original file line number Diff line number Diff line change
@@ -1,3 +1,6 @@
use std::time::{Duration, Instant};
use std::default::Default;

#[must_use]
#[derive(Debug, Default, Clone)]
pub struct Summary {
Expand All @@ -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<Duration> {
match self.timer {
Timer::DoneParsing(init, parse_time) | Timer::DoneFormatting(init, parse_time, _) => {
// This should never underflow since `Instant::now()` guarantees monotonicity.
Some(parse_time.duration_since(init))
}
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<Duration> {
match self.timer {
Timer::DoneFormatting(_init, parse_time, format_time) => {
Some(format_time.duration_since(parse_time))
}
Timer::DoneParsing(..) | Timer::Initialized(..) => None,
}
}

pub fn has_operational_errors(&self) -> bool {
self.has_operational_errors
}
Expand Down Expand Up @@ -65,3 +101,34 @@ impl Summary {
println!("{}", exit_codes);
}
}

#[derive(Clone, Copy, Debug)]
enum Timer {
Initialized(Instant),
DoneParsing(Instant, Instant),
DoneFormatting(Instant, Instant, Instant),
}

impl Default for Timer {
fn default() -> Self {
Timer::Initialized(Instant::now())
}
}

impl Timer {
fn done_parsing(self) -> Self {
match self {
Timer::Initialized(init_time) => Timer::DoneParsing(init_time, Instant::now()),
_ => 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, Instant::now())
}
_ => panic!("Timer can only transition to DoneFormatting from DoneParsing state"),
}
}
}