Add a number of progress indicators to Cargo #4646

alexcrichton · 2017-10-19T21:58:03Z

This commit is an attempt to stem the tide of "cargo is stuck updating the
registry" issues by giving a better indication as to what's happening in
long-running steps. The primary addition here is a Progress helper module
which prints and manages a progress bar for long-running operations like git
fetches, git checkouts, HTTP downloads, etc.

The second addition here is to print out when we've been stuck in resolve for
some time. We never really have a progress indicator for crate graph resolution
nor do we know when we're done updating sources. Instead we make a naive
assumption that when you've spent 0.5s in the resolution loop itself (not
updating deps) you're probably done updating dependencies and on to acutal
resolution. This will print out Resolving crate graph... and help inform that
Cargo is indeed not stuck looking at the registry, but rather it's churning away
in resolution.

Downloading all Servo's dependencies

Long running resolution

rust-highfive · 2017-10-19T21:58:06Z

r? @matklad

(rust_highfive has picked a reviewer for you, use r? to override)

alexcrichton · 2017-10-19T21:59:23Z

cc @rust-lang/cargo, a relatively significant change to Cargo's UI!

Mark-Simulacrum · 2017-10-19T22:26:24Z

Just to make sure, did we check that these have marginal impact on overall time spent on these steps?

I'm excited to see this happening, though it does seem rather unfortunate about the crate resolution being non-progress bar, and instead just "..."

joshtriplett · 2017-10-19T22:36:11Z

@Mark-Simulacrum We absolutely do need to measure this, before and after. I've seen reports of an issue with npm where ripping out progress reporting provided an order-of-magnitude performance improvement.

alexcrichton · 2017-10-19T23:03:11Z

@Mark-Simulacrum @joshtriplett good points! I haven't done much benchmarking yet because anything that touches the network is super variable, but there's a number of mitigations in place to avoid such a performance pitfall in the implementation.

matklad · 2017-10-20T07:41:27Z

src/cargo/core/shell.rs

+ extern crate kernel32;
+
+ pub fn stderr_width() -> Option<usize> {
+ unsafe {


I SEE A \t IN HERE! :)

matklad · 2017-10-20T07:43:48Z

src/cargo/util/progress.rs

+ fn drop(&mut self) {
+ clear(self.width, self.config);
+ }
+}


Is there a crate for this (=printing progress bars to console)?

There were a few yeah but this was simple enough and the existing crates were far enough (and/or too overpowered) for this use case so I figured it wasn't too bad to roll our own.

matklad · 2017-10-20T07:54:17Z

@alexcrichton looking at the first video, it looks like the Fetch progress bar can be repeated more than once, which looks confusing. So we might want to provide some more details, like printing an url you are fetching.

From the tool's perspective, I think in the far future it would be nice to be able to post progress in JSON messages, so that tools could also display progress. In IntelliJ at the moment we just draw an "indetermined" progress bar (always spinning one) and use the last Cargo message as a status. It's a surprisingly good user experience actually, but showing some real percentages would be better of course.

I haven't review the implementation to closely, but the two thoughts jump to mind:

I'd rather extract console progress bar into a separate crate (if there isn't one already): I expect there'll be a lot of interesting corner cases there for different OSes, so it should be easier to maintain this code outside of Cargo.

We have concerns about performance, and there's this funky waiting logic, so perhaps we could spin a separate thread to do all printing to the console?

alexcrichton · 2017-10-20T15:38:06Z

@matklad yeah the multiple "fetch" bars I believe are git submodules. Unfortunately we can't ever provide an actual progress indicator that's correct because we don't even know what submodules there are until we're done fetching the git repo itself. Sort of like resolution, the best I wanted to do was to indicate Cargo's process at a particular point in time. Ideally if Cargo's just sitting there you should be able to glance at the output and see what's happening is sort of my goal.

I don't really want to get into the business of extracting this to a separate crate. Sort of like the file locking implementation I'm sure it's useful to others but I'm already maintaining far too many crates as it is, and adding yet more where all we really need them to do is work for Cargo's needs would be a bit of a pain... I wouldn't be opposed to someone else extracting it, but there's certainly a plethora of progress indicator libraries on crates.io already and it may not be too beneficial to add one more?

I'm also not really sold on the need for a lot of performance tuning here personally. Updating the console at most 10 times a second seems like it shouldn't really cause problems, and otherwise all of Cargo's console I/O is on the main thread so I'm not sure why this would want to be different?

lukaslueg · 2017-10-20T18:08:55Z

We don't print the ==> thingy if stdout is not a tty, right?

aturon · 2017-10-20T18:44:01Z

@alexcrichton

This looks great! Should help a lot with perception.

Any chance we can detect and differentiate submodule fetching? If we don't, we will get questions about this forever.

Also, I naively found it confusing that the fetching steps seem to take quite a while, but the "downloading" steps don't. What's the difference, and can we communicate that a bit more clearly?

alexcrichton · 2017-10-20T19:08:16Z

@lukaslueg

Indeed yeah, this only all gets printed if stderr is a tty (aka a human is probably watching)

@aturon

Any chance we can detect and differentiate submodule fetching?

We can yeah, we certainly know when we're fetching for a submodule vs fetching for a "main repo". Note though that most projects don't have git deps, much less git deps with submodules, though.

Did you have something particular in mind in terms of what it would look like? There's not a huge amount of screen real-estate to work with, but I could imagine we could say something like "Fetching sub [=== ..."

What's the difference, and can we communicate that a bit more clearly?

Ah so today Cargo prints Updating https://... when it clones a git repository (or updates the registry's index). It then prints Downloading ... whenever it downloads a crate file from crates.io. These are actually very different steps in Cargo!

When we print Updating Cargo has no idea how many it's going to print, but in theory for Downloading Cargo always knows how many it's going to print (it doesn't today in the code, but we could figure it out).

Given that existing implementation my intention here was to just explain to the user what was happening if Cargo ever appeared to hang. Notably for slow-network situations or other oddities, basically just give a progress bar of some sort for network transfers. Note that Fetch [===...] shows up for Downloading as well, but in the videos above my network was just too fast to trigger that.

Does that make sense? Maybe we should rename the Downloading? Or maybe fold the Downloading into the progress bar entirely?

withoutboats · 2017-10-20T19:22:33Z

RE: downloading vs fetching. I think what this UI highlights which surprises people is that fetching git sources is part of the same step as updating the index, instead of part of the step in which crates are downloaded from crates.io.

servo is an interesting example in that it has so many and such complex git dependencies. Most crates will not see a status bar more than once because they exists entirely within the crates.io ecosystem.

alexcrichton · 2017-11-06T17:34:43Z

ping r? @matklad

This would be quite useful in debugging issues like #4187

matklad · 2017-11-06T17:37:21Z

Oh, yeah, sorry for forgetting about this :(

r=me with \t removed from here: https://github.com/rust-lang/cargo/pull/4646/files#diff-b53e068c2a295bd3080db1f2a6491fcfR319 :)

This commit is an attempt to stem the tide of "cargo is stuck updating the registry" issues by giving a better indication as to what's happening in long-running steps. The primary addition here is a `Progress` helper module which prints and manages a progress bar for long-running operations like git fetches, git checkouts, HTTP downloads, etc. The second addition here is to print out when we've been stuck in resolve for some time. We never really have a progress indicator for crate graph resolution nor do we know when we're done updating sources. Instead we make a naive assumption that when you've spent 0.5s in the resolution loop itself (not updating deps) you're probably done updating dependencies and on to acutal resolution. This will print out `Resolving crate graph...` and help inform that Cargo is indeed not stuck looking at the registry, but rather it's churning away in resolution.

alexcrichton · 2017-11-06T18:35:44Z

@bors: r=matklad

bors · 2017-11-06T18:35:45Z

📌 Commit 143b060 has been approved by matklad

Add a number of progress indicators to Cargo This commit is an attempt to stem the tide of "cargo is stuck updating the registry" issues by giving a better indication as to what's happening in long-running steps. The primary addition here is a `Progress` helper module which prints and manages a progress bar for long-running operations like git fetches, git checkouts, HTTP downloads, etc. The second addition here is to print out when we've been stuck in resolve for some time. We never really have a progress indicator for crate graph resolution nor do we know when we're done updating sources. Instead we make a naive assumption that when you've spent 0.5s in the resolution loop itself (not updating deps) you're probably done updating dependencies and on to acutal resolution. This will print out `Resolving crate graph...` and help inform that Cargo is indeed not stuck looking at the registry, but rather it's churning away in resolution. **Downloading all Servo's dependencies** [![asciicast](https://asciinema.org/a/JX9yQZtyFo5ED0Pwg45barBco.png)](https://asciinema.org/a/JX9yQZtyFo5ED0Pwg45barBco) **Long running resolution** [![asciicast](https://asciinema.org/a/p7xAkSVeMlkyvgcI6Gx7DZjAV.png)](https://asciinema.org/a/p7xAkSVeMlkyvgcI6Gx7DZjAV)

bors · 2017-11-06T18:35:52Z

⌛ Testing commit 143b060 with merge bac4884...

bors · 2017-11-06T19:22:27Z

☀️ Test successful - status-appveyor, status-travis
Approved by: matklad
Pushing bac4884 to master...

This notably brings in rust-lang/cargo#4646 which should help debugging a few issues and getting it out there for testing sooner.

Manishearth · 2017-11-17T00:26:25Z

Is this eventually going to be extended to show compilation progress as well? The current problem is that you have no idea what crates are actually being compiled, you just have the last few crates which started compiling (and you don't know when they finished). We don't need to show the progress of individual compilations, but being able to tell which compilations are currently running would be a major UI improvement.

paulrouget · 2017-11-20T07:08:28Z

Thank you so much for this feature! I have to pull big repos all the time, and even though it's just a cosmetic change, it makes the experience a lot better :)

Displays a one line progress of what crates are currently built. cc #2536, #3448. The change is based on #3451, but uses the progress bar introduced in #4646 instead. The percentage is simply the number of crates processed ÷ total crates count, which is inaccurate but better than nothing. Output looks like: [![asciicast](https://asciinema.org/a/YTiBAz4K4vfidNTAnehtyH46l.png)](https://asciinema.org/a/YTiBAz4K4vfidNTAnehtyH46l)

rust-highfive assigned matklad Oct 19, 2017

alexcrichton force-pushed the progress branch from 629cb44 to 58e36b5 Compare October 19, 2017 23:02

matklad reviewed Oct 20, 2017

View reviewed changes

src/cargo/core/shell.rs Outdated

extern crate kernel32;

pub fn stderr_width() -> Option<usize> {

unsafe {

Copy link

Member

matklad Oct 20, 2017

Choose a reason for hiding this comment

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

I SEE A \t IN HERE! :)

matklad reviewed Oct 20, 2017

View reviewed changes

lukaslueg mentioned this pull request Oct 30, 2017

Add a whoami command to display the logged in user #4625

Closed

This was referenced Oct 31, 2017

Cargo stuck for hours, taking 100% of the CPU #4604

Closed

cargo (nightly) just hangs there doing little https #4187

Closed

alexcrichton force-pushed the progress branch from 58e36b5 to 143b060 Compare November 6, 2017 18:35

bors merged commit 143b060 into rust-lang:master Nov 6, 2017

alexcrichton mentioned this pull request Nov 6, 2017

Update Cargo submodule rust-lang/rust#45813

Closed

alexcrichton added a commit to alexcrichton/rust that referenced this pull request Nov 7, 2017

Update Cargo submodule

28ed5bd

This notably brings in rust-lang/cargo#4646 which should help debugging a few issues and getting it out there for testing sooner.

alexcrichton deleted the progress branch November 17, 2017 14:42

kennytm mentioned this pull request Jun 8, 2018

Displays a one line progress of what crates are currently built. #5620

Merged

ehuss added this to the 1.23.0 milestone Feb 6, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add a number of progress indicators to Cargo #4646

Add a number of progress indicators to Cargo #4646

alexcrichton commented Oct 19, 2017

rust-highfive commented Oct 19, 2017

alexcrichton commented Oct 19, 2017

Mark-Simulacrum commented Oct 19, 2017

joshtriplett commented Oct 19, 2017

alexcrichton commented Oct 19, 2017

matklad Oct 20, 2017

matklad Oct 20, 2017 •

edited

Loading

alexcrichton Oct 20, 2017

matklad commented Oct 20, 2017

alexcrichton commented Oct 20, 2017

lukaslueg commented Oct 20, 2017

aturon commented Oct 20, 2017

alexcrichton commented Oct 20, 2017

withoutboats commented Oct 20, 2017 •

edited

Loading

alexcrichton commented Nov 6, 2017

matklad commented Nov 6, 2017

alexcrichton commented Nov 6, 2017

bors commented Nov 6, 2017

bors commented Nov 6, 2017

bors commented Nov 6, 2017

Manishearth commented Nov 17, 2017

paulrouget commented Nov 20, 2017

Add a number of progress indicators to Cargo #4646

Add a number of progress indicators to Cargo #4646

Conversation

alexcrichton commented Oct 19, 2017

rust-highfive commented Oct 19, 2017

alexcrichton commented Oct 19, 2017

Mark-Simulacrum commented Oct 19, 2017

joshtriplett commented Oct 19, 2017

alexcrichton commented Oct 19, 2017

matklad Oct 20, 2017

Choose a reason for hiding this comment

matklad Oct 20, 2017 • edited Loading

Choose a reason for hiding this comment

alexcrichton Oct 20, 2017

Choose a reason for hiding this comment

matklad commented Oct 20, 2017

alexcrichton commented Oct 20, 2017

lukaslueg commented Oct 20, 2017

aturon commented Oct 20, 2017

alexcrichton commented Oct 20, 2017

withoutboats commented Oct 20, 2017 • edited Loading

alexcrichton commented Nov 6, 2017

matklad commented Nov 6, 2017

alexcrichton commented Nov 6, 2017

bors commented Nov 6, 2017

bors commented Nov 6, 2017

bors commented Nov 6, 2017

Manishearth commented Nov 17, 2017

paulrouget commented Nov 20, 2017

matklad Oct 20, 2017 •

edited

Loading

withoutboats commented Oct 20, 2017 •

edited

Loading