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

Make tests capture the error printed by a Result return #102794

Merged
merged 1 commit into from
Oct 10, 2022

Conversation

dtolnay
Copy link
Member

@dtolnay dtolnay commented Oct 7, 2022

An error returned by tests previously would get written directly to stderr, instead of to the capture buffer set up by the test harness. This PR makes it write to the capture buffer so that it can be integrated as part of the test output by build tools such as buck test, since being able to read the error message returned by a test is pretty critical to debugging why the test failed.


Before:

// tests/test.rs

#[test]
fn test() -> Result<(), &'static str> {
    println!("STDOUT");
    eprintln!("STDERR");
    Err("RESULT")
}
$ cargo build --test test
$ target/debug/deps/test-???????????????? -Z unstable-options --format=json
{ "type": "suite", "event": "started", "test_count": 1 }
{ "type": "test", "event": "started", "name": "test" }
Error: "RESULT"
{ "type": "test", "name": "test", "event": "failed", "stdout": "STDOUT\nSTDERR\n" }
{ "type": "suite", "event": "failed", "passed": 0, "failed": 1, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": 0.00040313 }

After:

$ target/debug/deps/test-???????????????? -Z unstable-options --format=json
{ "type": "suite", "event": "started", "test_count": 1 }
{ "type": "test", "event": "started", "name": "test" }
{ "type": "test", "name": "test", "event": "failed", "stdout": "STDOUT\nSTDERR\nError: \"RESULT\"" }
{ "type": "suite", "event": "failed", "passed": 0, "failed": 1, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": 0.000261894 }

@rustbot rustbot added the T-libs Relevant to the library team, which will review and decide on the PR/issue. label Oct 7, 2022
@rust-highfive
Copy link
Collaborator

r? @thomcc

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

@rustbot
Copy link
Collaborator

rustbot commented Oct 7, 2022

Hey! It looks like you've submitted a new PR for the library teams!

If this PR contains changes to any rust-lang/rust public library APIs then please comment with @rustbot label +T-libs-api -T-libs to tag it appropriately. If this PR contains changes to any unstable APIs please edit the PR description to add a link to the relevant API Change Proposal or create one if you haven't already. If you're unsure where your change falls no worries, just leave it as is and the reviewer will take a look and make a decision to forward on if necessary.

Examples of T-libs-api changes:

  • Stabilizing library features
  • Introducing insta-stable changes such as new implementations of existing stable traits on existing stable types
  • Introducing new or changing existing unstable library APIs (excluding permanently unstable features / features without a tracking issue)
  • Changing public documentation in ways that create new stability guarantees
  • Changing observable runtime behavior of library APIs

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Oct 7, 2022
@rust-log-analyzer

This comment has been minimized.

@dtolnay
Copy link
Member Author

dtolnay commented Oct 7, 2022

/checkout/src/test/rustdoc-gui/basic-code.goml basic-code... FAILED
[ERROR] (line 3) expected 1 elements, found 0: for command `assert-count: (".src-line-numbers", 1)`

Same failure as #102744 (comment) which succeeded after retry, so very likely unrelated to this PR.

@thomcc
Copy link
Member

thomcc commented Oct 8, 2022

Huh, yeah, the termination impl directly had writeln!(io::stderr(), ...) before rather than the output redirect, which would definitely be a bug. Pretty subtle -- I'm not a huge fan of how test output redirection works (at all), and would love another solution for it but haven't found one that isn't it's own brand of horrifying.

Anyway, this is a really nice improvement even outside of an external test runner. The current output comes out pretty weirdly in this situation too; it's not where you'd expect, and often is intermixed with the list of running tests.

This can be pretty confusing, since it's not somewhere that is supposed to have information, and it's quite bad that the thing that caused the test to fail is not in the area where we display the information about the test failures.

For example
$ cargo test
    Finished test [unoptimized + debuginfo] target(s) in 0.00s
     Running unittests src/lib.rs (target/debug/deps/testprinttest-777d764775ed5046)

running 3 tests
Error: "test3 return"
Error: "test1 return"
test test3 ... FAILED
Error: "test2 return"
test test1 ... FAILED
test test2 ... FAILED

failures:

---- test3 stdout ----
test3 stdout
test3 stderr

---- test1 stdout ----
test1 stdout
test1 stderr

---- test2 stdout ----
test2 stdout
test2 stderr


failures:
    test1
    test2
    test3

test result: FAILED. 0 passed; 3 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

error: test failed, to rerun pass `--lib`

for

#[test]
fn test1() -> Result<(), &'static str> {
    println!("test1 stdout");
    eprintln!("test1 stderr");
    Err("test1 return")
}

#[test]
fn test2() -> Result<(), &'static str> {
    println!("test2 stdout");
    eprintln!("test2 stderr");
    Err("test2 return")
}

#[test]
fn test3() -> Result<(), &'static str> {
    println!("test3 stdout");
    eprintln!("test3 stderr");
    Err("test3 return")
}

I'm pretty sure I've seen this before too, and I'm sure many others have as well -- but it only happens when you also have a failing test to deal with, so probably generally a distracted state. Thanks.

@bors r+

@bors
Copy link
Contributor

bors commented Oct 8, 2022

📌 Commit 293f662 has been approved by thomcc

It is now in the queue for this repository.

@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 Oct 8, 2022
Dylan-DPC added a commit to Dylan-DPC/rust that referenced this pull request Oct 9, 2022
Make tests capture the error printed by a Result return

An error returned by tests previously would get written directly to stderr, instead of to the capture buffer set up by the test harness. This PR makes it write to the capture buffer so that it can be integrated as part of the test output by build tools such as `buck test`, since being able to read the error message returned by a test is pretty critical to debugging why the test failed.

<br>

**Before:**

```rust
// tests/test.rs

#[test]
fn test() -> Result<(), &'static str> {
    println!("STDOUT");
    eprintln!("STDERR");
    Err("RESULT")
}
```

```console
$ cargo build --test test
$ target/debug/deps/test-???????????????? -Z unstable-options --format=json
{ "type": "suite", "event": "started", "test_count": 1 }
{ "type": "test", "event": "started", "name": "test" }
Error: "RESULT"
{ "type": "test", "name": "test", "event": "failed", "stdout": "STDOUT\nSTDERR\n" }
{ "type": "suite", "event": "failed", "passed": 0, "failed": 1, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": 0.00040313 }
```

**After:**

```console
$ target/debug/deps/test-???????????????? -Z unstable-options --format=json
{ "type": "suite", "event": "started", "test_count": 1 }
{ "type": "test", "event": "started", "name": "test" }
{ "type": "test", "name": "test", "event": "failed", "stdout": "STDOUT\nSTDERR\nError: \"RESULT\"" }
{ "type": "suite", "event": "failed", "passed": 0, "failed": 1, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": 0.000261894 }
```
bors added a commit to rust-lang-ci/rust that referenced this pull request Oct 10, 2022
Rollup of 6 pull requests

Successful merges:

 - rust-lang#99696 (Uplift `clippy::for_loops_over_fallibles` lint into rustc)
 - rust-lang#102055 (Move some tests to more reasonable directories)
 - rust-lang#102786 (Remove tuple candidate, nothing special about it)
 - rust-lang#102794 (Make tests capture the error printed by a Result return)
 - rust-lang#102853 (Skip chained OpaqueCast when building captures.)
 - rust-lang#102868 (Rename `AssocItemKind::TyAlias` to `AssocItemKind::Type`)

Failed merges:

r? `@ghost`
`@rustbot` modify labels: rollup
@bors bors merged commit 302bf31 into rust-lang:master Oct 10, 2022
@rustbot rustbot added this to the 1.66.0 milestone Oct 10, 2022
@dtolnay dtolnay deleted the termination branch November 2, 2022 18:59
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. T-libs Relevant to the library team, which will review and decide on the PR/issue.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants