a-b-street/abstreet
1
1
Fork 0
mirror of https://github.com/a-b-street/abstreet.git synced 2024-12-27 00:12:55 +03:00
Code Issues Projects Releases Wiki Activity

When a timer finishes, print the wannabe flamechart using the log crate.

Browse Source 
On native, this makes it much easier to visually distinguish the
finalized timing breakdown from the temporary progress messages. On web,
this makes the timing breakdown actually show up in the developer
console.
This commit is contained in:
Dustin Carlino 2021-10-21 13:56:17 -07:00
parent 9f86365cf6
commit 151ec7b167
3 changed files with 45 additions and 37 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
abstutil/src/cli.rs
View File

@ -21,7 +21,7 @@ impl CmdArgs {
let raw = match parse_args() {
Ok(raw) => raw,
Err(err) => {
log::warn!("Didn't parse arguments from URL query params: {}", err);
warn!("Didn't parse arguments from URL query params: {}", err);
Vec::new()
}
};

4
abstutil/src/lib.rs
View File

@ -7,8 +7,10 @@
#[macro_use]
extern crate anyhow;
#[macro_use]
extern crate log;
// I'm not generally a fan of wildcard exports, but they're more maintable here.
// I'm not generally a fan of wildcard exports, but they're more maintainable here.
pub use crate::serde::*;
pub use cli::*;
pub use clone::*;

76
abstutil/src/time.rs
View File

@ -56,7 +56,7 @@ impl Progress {
prettyprint_time(elapsed)
);
if self.total_items == 1 {
Timer::selfless_println(maybe_sink, line.clone());
temporary_println(maybe_sink, line.clone());
} else {
clear_current_line();
println!("{}", line);
@ -147,23 +147,8 @@ impl<'a> Timer<'a> {
Timer::new("throwaway")
}
fn println(&mut self, line: String) {
Timer::selfless_println(&mut self.sink, line);
}
// Workaround for borrow checker
fn selfless_println(maybe_sink: &mut Option<Box<dyn TimerSink + 'a>>, line: String) {
#[cfg(not(target_arch = "wasm32"))]
{
println!("{}", line);
}
#[cfg(target_arch = "wasm32")]
{
log::debug!("{}", line);
}
if let Some(ref mut sink) = maybe_sink {
sink.println(line);
}
fn temporary_println(&mut self, line: String) {
temporary_println(&mut self.sink, line);
}
/// Used to end the scope of a timer early.
@ -175,7 +160,7 @@ impl<'a> Timer<'a> {
}
let name = raw_name.into();
self.println(format!("{}...", name));
self.temporary_println(format!("{}...", name));
self.stack.push(StackEntry::TimerSpan(TimerSpan {
name,
started_at: Instant::now(),
@ -205,7 +190,7 @@ impl<'a> Timer<'a> {
s.nested_results.push(format!("{}- {}", padding, line));
s.nested_results.extend(span.nested_results);
if span.nested_time != 0.0 {
Timer::selfless_println(
temporary_println(
&mut self.sink,
format!(
"{}... plus {}",
@ -226,7 +211,7 @@ impl<'a> Timer<'a> {
self.results.push(format!("{}- {}", padding, line));
self.results.extend(span.nested_results);
if span.nested_time != 0.0 {
self.println(format!(
self.temporary_println(format!(
"{}... plus {}",
name,
prettyprint_time(elapsed - span.nested_time)
@ -240,7 +225,7 @@ impl<'a> Timer<'a> {
}
}
self.println(line);
self.temporary_println(line);
}
pub fn start_iter<S: Into<String>>(&mut self, raw_name: S, total_items: usize) {
@ -417,16 +402,16 @@ impl<'a> std::ops::Drop for Timer<'a> {
match self.stack.last() {
Some(StackEntry::TimerSpan(ref s)) => {
if s.name != stop_name {
println!("dropping Timer during {}, due to panic?", s.name);
error!("dropping Timer during {}, due to panic?", s.name);
return;
}
}
Some(StackEntry::File(ref r)) => {
println!("dropping Timer while reading {}, due to panic?", r.path);
error!("dropping Timer while reading {}, due to panic?", r.path);
return;
}
Some(StackEntry::Progress(ref p)) => {
println!(
error!(
"dropping Timer while doing progress {}, due to panic?",
p.label
);
@ -437,19 +422,17 @@ impl<'a> std::ops::Drop for Timer<'a> {
self.stop(&stop_name);
assert!(self.stack.is_empty());
self.println(String::new());
for line in &self.results {
Timer::selfless_println(&mut self.sink, line.to_string());
finalized_println(&mut self.sink, line.to_string());
}
if std::thread::panicking() {
self.println(String::new());
self.println(String::new());
self.println(String::new());
self.println(String::new());
self.println(
"!!! The program panicked, look above for the stack trace !!!".to_string(),
);
error!("");
error!("");
error!("");
error!("");
error!("");
error!("!!! The program panicked, look above for the stack trace !!!");
}
}
}
@ -534,7 +517,7 @@ impl<'a> Read for Timer<'a> {
);
if self.outermost_name != "throwaway" {
if file.last_printed_at.is_none() {
self.println(line.clone());
self.temporary_println(line.clone());
} else {
clear_current_line();
println!("{}", line);
@ -576,3 +559,26 @@ impl<'a> Read for Timer<'a> {
Ok(bytes)
}
}
// Print progress info while a Timer is still active. Invisible on web by default.
fn temporary_println<'a>(maybe_sink: &mut Option<Box<dyn TimerSink + 'a>>, line: String) {
#[cfg(not(target_arch = "wasm32"))]
{
println!("{}", line);
}
#[cfg(target_arch = "wasm32")]
{
debug!("{}", line);
}
if let Some(ref mut sink) = maybe_sink {
sink.println(line);
}
}
// Print info about a completed Timer. Always uses info logs, so works on native and web.
fn finalized_println<'a>(maybe_sink: &mut Option<Box<dyn TimerSink + 'a>>, line: String) {
info!("{}", line);
if let Some(ref mut sink) = maybe_sink {
sink.println(line);
}
}