Console output should better reflect the build process

[nnethercote]

Describe the problem you are trying to solve

The console output can be misleading about what's happening in the build. Having lots of sequential Compiling <crate> lines makes it seem like compilation is serial, and if a slow-building crate X starts building just before a fast-building crate Y, you'll probably think that Y is the slow-building crate. (I was misled in this way about build times of different crates within rustc for a long time.)

The progress bar helps with this, because it shows which crates are currently being built... but only if you have a sufficiently wide terminal. If you have 80 chars you don't see them at all. If you have 100 chars you might see one or two or three, but any crate with a long name greatly reduces the effectiveness.

Also, linking isn't shown. This means people often blame the compiler for slowness when it's the linker's fault.

Describe the solution you'd like

1. Instead of printing Compiling <crate> when a crate starts building, print Compiled <crate> in X.YYs. That would avoid the problem where slowness to build is blamed on the wrong crate. This is a change of tense in the message, but Cargo already mixes present and past tenses, e.g. with Downloaded <crate> and Downloaded2 3 crates (78.7 KB) in 1.03s messages.

2. Shrink the width of the progress bar, so the crates being built can be seen even on narrow terminals.

3. Show linking as a distinct step, including the time it took, e.g. `Linked in X.YYs".

Notes

My motivation here was comparing console output (which is moderately useful) to -Ztimings output (which is amazing), and trying to make the former a bit more like the latter.

See also

• Collect warnings for path dependencies into one message printed at the end #8749
• Ability to suppress "Finished dev target" and "Running <path>" lines without hiding progress indicators #8743
• Cargo should use standard logging framework #6751

[nnethercote]

2. Shrink the width of the progress bar, so the crates being built can be seen even on narrow terminals.

#8892 does this.

[ehuss]

I don't think it is currently possible to show link time as a separate stat, since rustc does compilation+linking together. It might be possible to have rustc spit out a JSON message when it starts linking, and Cargo could catch that to start a new timer. There might be a tiny delay, but I suspect not enough to affect the timing in a meaningful way. I think that would be useful (at least for -Ztimings). Would need to ask the compiler team what they think about adding instrumentation like that.

[nnethercote]

Maybe Cargo could output "Compiling and linking" (or "Compiled and linked") instead? Less precise, but still clearer than the current output.

[alexcrichton]

The intention of the current progress bar was to give an indicator as to what's currently compiling so we don't have to just read the last line and blame that (ideally), but it's true that we never got back to updating the console output otherwise. I'd be a bit wary of indicating the compile time of each crate individually because that could add up to a lot of noise in the current output scheme.

All that being said though, I think it's high time we completely revamp Cargo's output. Even one-short-line-per-package feels unnecessarily verbose today. I'd sort of prefer if we could have the progress bar we currently have but have maybe at most 4-5 other lines indicating "these were the slowest crates to compile" or something like that. Then when Cargo finishes it could erase the output or leave it all there. (or something like that).

Basically I think the current output has gotten us this far but it could benefit from a complete overhaul in addition to smaller tweaks.

[joshtriplett]

@ehuss We've talked about, for other reasons, separating compilation and linking: rust-lang/rust#64191

If we do that in rustc, cargo should use that, and could then reflect that in its output.

[dtolnay]

I think it's high time we completely revamp Cargo's output. Even one-short-line-per-package feels unnecessarily verbose today.

Sharing two recordings for possible inspiration. Both of these build systems' outputs are designed around accurately surfacing where the most time is getting spent in builds with (extremely) high parallelism. The currently running longest running jobs are always at the top.

[ehuss]

Thanks @dtolnay for sharing those. I'm not too familiar with what kind of terminal detection and support is necessary to be able to create multi-line progress indicators like that, especially across a myriad of platforms. Cargo's current progress bar is extremely primitive, which makes it a little easier to maintain, but is much more limiting.

I think it would be great to improve the output, I just hope it doesn't require pulling in large dependencies, or require heroic efforts to get it to work across terminals. Cygwin/msys on Windows has been particularly hard to support, since Cargo doesn't live in the Cygwin universe, it is limited on what it can do.

I'm also curious how warnings and errors get displayed. One problem I struggled with in the current progress bar implementation is that it has to clear the progress bar in order to display a message (and scroll the output up), and then redisplay the progress bar. This causes severe flickering on some terminals (particularly on Windows). I'm curious how buck and bazel and other tools handle that.

[camsteffen]

Minor suggestion. The list of crates in the Building line should match the order that they are printed in the Compiling lines. That is, the one that has been running the longest should be first, IIUC.

[arcuru]

I am interested in working on this, and have already created a hacky prototype build using crossterm that is heavily influenced by buck/bazel. See the recording below.

@alexcrichton @ehuss @dtolnay Since this is pretty old, could you confirm if you'd actually want to take this change? It's a decent chunk of work to do it properly so I don't want to spend too much time on it if you're no longer interested.