Skip to content
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

Consistently use crate::display_error on errors during drain #10394

Merged
merged 2 commits into from
Mar 21, 2022

Conversation

dtolnay
Copy link
Member

@dtolnay dtolnay commented Feb 16, 2022

As suggested in #10383 (comment) and #10383 (comment).

@rust-highfive
Copy link

r? @ehuss

(rust-highfive has picked a reviewer for you, use r? to override)

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Feb 16, 2022
Comment on lines -842 to 849
if let Err(e) = self.timings.finished(cx, &error) {
if error.is_some() {
crate::display_error(&e, &mut cx.bcx.config.shell());
} else {
return Some(e);
}
if let Err(e) = self.timings.finished(cx, &errors.to_error()) {
self.handle_error(&mut cx.bcx.config.shell(), &mut errors, e);
}
Copy link
Member Author

Choose a reason for hiding this comment

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

In response to:

I'm finding it a bit confusing to follow why above cases use handle_error but self.timings.finished and the writeln! below both use different custom logic. I think, however, that it should be fine to use handle_error in both cases?

Copy link
Contributor

Choose a reason for hiding this comment

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

Yea, I think it should be fine. It's been a while, but I think my thought process was that "if something has gone wrong, might as well exit right away". The consequence is that you might end up with multiple errors displayed.

Comment on lines 893 to 895
if err_state.is_some() {
// Already encountered one error.
log::warn!("{:?}", new_err);
} else if !self.active.is_empty() {
crate::display_error(&new_err, shell);
crate::display_error(&new_err, shell);
if !self.active.is_empty() && err_state.count == 0 {
drop(shell.warn("build failed, waiting for other jobs to finish..."));
*err_state = Some(anyhow::format_err!("build failed"));
} else {
*err_state = Some(new_err);
}
Copy link
Member Author

Choose a reason for hiding this comment

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

In response to:

I believe the original intention of this code was, when possible, to return upwards the error we encountered during compilation if only one was encountered. That being said, however, I don't believe we can reliably return upwards an error so I think it would be better to unconditionally, for any errors encountered during the build, to use crate::display_error and print them here. That way there's much less juggling of trying to preserve some "main" error to return while also ensuring that all other errors are printed.

@dtolnay
Copy link
Member Author

dtolnay commented Feb 17, 2022

CI failure appears unrelated. It looks like there are a bunch of new deprecations in clap 3.1.0.
https://github.com/clap-rs/clap/releases/tag/v3.1.0

error: use of deprecated struct `clap::App`: Replaced with `Command`
  --> src/cargo/util/command_prelude.rs:25:22
   |
25 | pub type App = clap::App<'static>;
   |                      ^^^
   |
note: the lint level is defined here
  --> src/cargo/lib.rs:4:24
   |
4  | #![cfg_attr(test, deny(warnings))]
   |                        ^^^^^^^^
   = note: `#[deny(deprecated)]` implied by `#[deny(warnings)]`

error: use of deprecated variant `clap::AppSettings::DontCollapseArgsInUsage`: Replaced with `Command::dont_collapse_args_in_usage` and `Command::is_dont_collapse_args_in_usage_set`
   --> src/cargo/util/command_prelude.rs:284:75
    |
284 |     App::new(name).setting(AppSettings::DeriveDisplayOrder | AppSettings::DontCollapseArgsInUsage)
    |                                                                           ^^^^^^^^^^^^^^^^^^^^^^^

@dtolnay dtolnay mentioned this pull request Feb 17, 2022
Copy link
Member

@alexcrichton alexcrichton left a comment

Choose a reason for hiding this comment

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

Looks good to me, thanks! It feels a little wonky with AlreadyPrintedError being needed because the error wrapped up in AlreadyPrintedError hasn't actually ever been printed, but I presume you mostly didn't want to change the output of Cargo's failure to be more verbose?

@dtolnay
Copy link
Member Author

dtolnay commented Feb 17, 2022

Yeah I didn't think this cleanup justified adding +3 lines of meaningless output to every Cargo run. It's +3 because the context from here is still printed, so it's the difference between:

error: could not compile `repro` due to previous error

vs:

error: could not compile `repro` due to previous error

Caused by:
  1 job failed

Alternatively it would be possible to make drain_the_queue return bool or equivalent instead of Option<anyhow::Error>, and having could not compile `repro` due to previous error be the origin of the error instead of a context, but that ends up being more complex in more code.

@dtolnay
Copy link
Member Author

dtolnay commented Feb 17, 2022

log::warn!("{:?}", new_err);
} else if !self.active.is_empty() {
crate::display_error(&new_err, shell);
crate::display_error(&new_err, shell);
Copy link
Member Author

Choose a reason for hiding this comment

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

I don't fully understand why, but this breaks build::close_output in the test suite.

The failure looks like:

---- build::close_output stdout ----
thread 'build::close_output' panicked at 'called `Result::unwrap()` on an `Err` value: Expected lines did not match (ignoring order):
0   100002     Compiling foo v0.1.0 (/home/runner/work/cargo/cargo/target/tmp/cit/t231/foo)
1   0     hello stderr!
2   0     error: Broken pipe (os error 32)
3   99999  warning: build failed, waiting for other jobs to finish...
4   0     error: Broken pipe (os error 32)
    5    +error: Broken pipe (os error 32)
    6    +error: Broken pipe (os error 32)
    7    +error: Broken pipe (os error 32)
    8    +error: Broken pipe (os error 32)
    9    +error: Broken pipe (os error 32)
    10   +error: Broken pipe (os error 32)
    11   +error: Broken pipe (os error 32)
    12   +error: Broken pipe (os error 32)
    13   +error: Broken pipe (os error 32)
    14   +error: Broken pipe (os error 32)
    15   +error: Broken pipe (os error 32)
    16   +error: Broken pipe (os error 32)
    17   +error: Broken pipe (os error 32)
    18   +error: Broken pipe (os error 32)
    19   +error: Broken pipe (os error 32)
    20   +error: Broken pipe (os error 32)
[...]
    99989 +error: Broken pipe (os error 32)
    99990 +error: Broken pipe (os error 32)
    99991 +error: Broken pipe (os error 32)
    99992 +error: Broken pipe (os error 32)
    99993 +error: Broken pipe (os error 32)
    99994 +error: Broken pipe (os error 32)
    99995 +error: Broken pipe (os error 32)
    99996 +error: Broken pipe (os error 32)
    99997 +error: Broken pipe (os error 32)
    99998 +error: Broken pipe (os error 32)
    99999 +error: Broken pipe (os error 32)
    100000 +error: Broken pipe (os error 32)
    100001 +error: Broken pipe (os error 32)
    100002 +error: Broken pipe (os error 32)

', tests/testsuite/build.rs:5680:6
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    build::close_output

test result: FAILED. 2298 passed; 1 failed; 6 ignored; 0 measured; 0 filtered out; finished in 506.90s

The test involves a proc macro where we close its stdout and then execute println! 100,000 times from the macro. I believe println is supposed to panic on io error so I am confused how the macro keeps going and prints 99,999 more times after the first println has failed.

The test passes after the following diff:

-         crate::display_error(&new_err, shell);
+         if err_state.count > 1 {
+             log::warn!("{:?}", new_err);
+         } else {
+             crate::display_error(&new_err, shell);
+         }

Copy link
Member

Choose a reason for hiding this comment

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

I believe the reason for this is that the main loop here gets one-line-at-a-time from the proc-macro, which is 100k prints. Each print fails because of a broken pipe, so Cargo tries to handle the error 100k times.

Short of specifically handling broken pipe errors here I'm not entirely sure what to do. We don't want to drop errors on the floor, especially with your future PR of continuing on error, so they need to be handled somehow I think?

Copy link
Contributor

@ehuss ehuss Mar 2, 2022

Choose a reason for hiding this comment

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

I'm a little concerned specifically about this change (and I realize it is the crux of this PR). It was pretty intentional to not show any errors after the first due to scenarios like this, where Cargo could just spew a bunch of error messages, but only one is really relevant.

Perhaps it is possible to put errors into two categories, one which is "important" and should be shown no matter what, and the other where it should only be shown if no other error has been shown? I think the only error that fits the former category is this one, which is the "could not compile foo…" error. The rest of the errors are all things like failed to write to stdout or other internal errors that aren't too critical to display if something else has gone wrong. Would it be possible to wrap that error up in such a way that it will only show duplicates for that?

That will still result in more errors being display (imagine there are 16 crates building in parallel and they all fail), but I think that's probably fine (and maybe even preferred?).

There still would be some risk that some relevant error would get elided, but at the moment I don't see any that really matter (and wouldn't be any worse than it is today).

Copy link
Member Author

Choose a reason for hiding this comment

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

I have update the PR to revert to log::warn! instead of crate::display_error for errors after the first, except for the Message::Finish error that you flagged as important.

@@ -5672,7 +5672,6 @@ fn close_output() {
hello stderr!
[ERROR] [..]
[WARNING] build failed, waiting for other jobs to finish...
[ERROR] [..]
Copy link
Member Author

Choose a reason for hiding this comment

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

The error going away on this line is the "build failed" error from the following line. It's preceded by the actual error, and a "build failed, waiting for other jobs to finish..." message.

*err_state = Some(anyhow::format_err!("build failed"));

@ehuss
Copy link
Contributor

ehuss commented Mar 21, 2022

Thanks!

@bors r+

@bors
Copy link
Contributor

bors commented Mar 21, 2022

📌 Commit 809bcfe has been approved by ehuss

@bors bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Mar 21, 2022
@bors
Copy link
Contributor

bors commented Mar 21, 2022

⌛ Testing commit 809bcfe with merge 5e09899...

@bors
Copy link
Contributor

bors commented Mar 21, 2022

☀️ Test successful - checks-actions
Approved by: ehuss
Pushing 5e09899 to master...

@bors bors merged commit 5e09899 into rust-lang:master Mar 21, 2022
@dtolnay dtolnay deleted the displayerror branch March 21, 2022 21:38
bors added a commit to rust-lang-ci/rust that referenced this pull request Mar 31, 2022
Update cargo

13 commits in 109bfbd055325ef87a6e7f63d67da7e838f8300b..1ef1e0a12723ce9548d7da2b63119de9002bead8
2022-03-17 21:43:09 +0000 to 2022-03-31 00:17:18 +0000
- Support `-Zmultitarget` in cargo config (rust-lang/cargo#10473)
- doc: Fix document url for libcurl format (rust-lang/cargo#10515)
- Fix wrong info in "Environment variables" docs (rust-lang/cargo#10513)
- Use the correct flag in --locked --offline error message (rust-lang/cargo#10512)
- Don't treat host/target duplicates as duplicates (rust-lang/cargo#10466)
- Unstable --keep-going flag (rust-lang/cargo#10383)
- Part 1 of RFC2906 - Packages can inherit fields from their root workspace (rust-lang/cargo#10497)
- Remove unused profile support for -Zpanic-abort-tests (rust-lang/cargo#10495)
- HTTP registry implementation (rust-lang/cargo#10470)
- Add a notice about review capacity. (rust-lang/cargo#10501)
- Add tests for ignoring symlinks (rust-lang/cargo#10047)
- Update doc string for deps_of/compute_deps. (rust-lang/cargo#10494)
- Consistently use crate::display_error on errors during drain (rust-lang/cargo#10394)
@ehuss ehuss added this to the 1.61.0 milestone Apr 7, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants