Skip to content

feat: Print sourcemaps/files operations timings information - #995

Merged
kamilogorek merged 4 commits into
masterfrom
files-operation-timings
Jul 7, 2021
Merged

kamilogorek merged 4 commits into
masterfrom
files-operation-timings

Conversation

@kamilogorek

Copy link
Copy Markdown
Contributor

Before:

image

After

image

@kamilogorek
kamilogorek force-pushed the files-operation-timings branch from 3941128 to 218d0c8 Compare July 6, 2021 14:58
@kamilogorek
kamilogorek enabled auto-merge (squash) July 6, 2021 15:06

@lobsterkatie lobsterkatie left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can't speak to the rust-specific changes, but overall this looks good, and I definitely think it will be helpful for debugging!

Nit: There's inconsistency in terms of what we log and when. Sometimes it's

Doing X
Did X in 123 ms

sometimes it's

Did X in 123 ms
Did X to 5 files

sometimes it's

Doing X

and sometimes it's

Did X in 123 ms

In a perfect world, IMHO it'd be

Doing X
    Did X in 123 ms

or

Doing X
    Did X to 5 files in 123 ms

as makes sense in context.

(I recognize this isn't a perfect world, though, so feel free to take this with however many grains of salt you'd like.)

Comment thread src/utils/progress.rs Outdated

pub fn finish_with_duration(&self, op: &str) {
let e = self.inner.elapsed();
let msg = format!("{} completed in {}.{}s", op, e.as_secs(), e.as_millis());

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do as_secs() and as_millis() give the second and millisecond parts of the time, or do they do what their names imply and give the same time expressed in different units?

If the latter, it seems like this would be problematic in the case of something which took, say, 873 ms - in seconds that's 1 second, so you'd end up with completed in 1.873s, which obviously isn't correct.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are totally correct, great catch, thanks!

Comment thread src/utils/dif_upload.rs
walk_difs_directory(base_path, options, |source, name, buffer| {
debug!("trying to process {}", name);
progress.set_message(&name);
progress.set_message(name.to_owned());

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Rust Q, do we always prefer to_owned over clone because it's more generic? (to_owned might not clone right? - depends on the trait impl)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

clone() on &str returns a &str, where in this case to_owned will return String which we need for set_message. I prefer to_owned as it's more explicit and obvious what are you want to get out of that call.

Comment thread src/utils/progress.rs
self.inner.set_style(progress_style);
self.inner.set_prefix(">");
self.inner.finish_with_message(msg);
logging::set_progress_bar(None);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't we use self.finish_with_message(&msg) to avoid duplicating the logic here?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was thinking about it but decided no to do that to keep everything in line. This way, every method is a standalone thing that just proxies data to indicatif methods. It's very rarely touched part of code and adds 1 more line of code anyway.

Comment thread src/utils/progress.rs Resolved
@kamilogorek

Copy link
Copy Markdown
Contributor Author

@lobsterkatie totally agrees. The problem here is that some messages are displayed using raw println!() and some through the progress bar. Those that use the progress bar are disregarded after the operation is complete and overwritten by estimates now, that's why sometimes it may look out of order or illogical. We also don't have all the data stored necessary to show things like Added source map references to X files. But it's definitely something we can iterate over.

@kamilogorek
kamilogorek merged commit 0af0856 into master Jul 7, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants