eprintln prints to stdout in a test

[KnorrFG]

Problem

In a test, eprintln prints to stdout.

Steps

1. Create a new cargo project.
2. Add the following source as integration test

use std::io::Write;

#[test]
fn good() {
    println!("This should go to stdout");
    eprintln!("This shoud go to stderr");
    _ = writeln!(std::io::stderr(), "This should REALLY go to stdout");
}

#[test]
fn bad() {
    println!("This should go to stdout (bad test)");
    eprintln!("This shoud go to stderr (bad test)");
    _ = writeln!(
        std::io::stderr(),
        "This should REALLY go to stdout (bad test)"
    );
    panic!("I am a failure");
}

3. Run cargo test and observe output, which, btw, looks like this:

$ cargo test --test foo
   Compiling testtest v0.1.0 (/tmp/testtest)
    Finished test [unoptimized + debuginfo] target(s) in 0.13s
     Running tests/foo.rs (/tmp/testtest/target/debug/deps/foo-9896c48b30738b26)

running 2 tests
This should REALLY go to stdout (bad test)
This should REALLY go to stdout
test good ... ok
test bad ... FAILED

failures:

---- bad stdout ----
This should go to stdout (bad test)
This shoud go to stderr (bad test)
thread 'bad' panicked at tests/foo.rs:17:5:
I am a failure
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    bad

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

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

Possible Solution(s)

Make eprintln print to stderr. If the current behavior is actually intended, it should at least be documented, but isn't (I checked the cargo test docs, and the eprintln docs)

Notes

I think by default, a test should capture stdout and stderr, but not just silently redirect the eprintln macro.

Version

cargo 1.76.0 (c84b36747 2024-01-18)

EDIT (one day later): I just realized that I messed up the strings. The String "This should REALLY go to stdout" should of course be "This should REALLY go to stderr", with the same applying to the bad test variant.

[epage]

Could you expand on the reason this makes a difference?

Also, does this reproduce with --nocapture? If so, is that sufficient?

[KnorrFG]

If you use other libraries that actually do print to stderr, and you see that output showing up, while the outputs of eprintln are missing, you'll (wrongly) assume that the eprintln calls were not executed, and that your test contains some strange bugs that mess up the control flow badly. If you know about this behavior, it is much less of a problem, and using --nocapture makes it also less of a problem. However, neither is the case by default.

[epage]

So you know which stream the underlying production code is meant to write to and you are splitting the streams (e.g. 2>) to capture that specific stream?

Or are you not wanting eprint to be captured? I'm realizing this issue is missing an example of expected behavior that contrasts with the reproductoon case, so the request is less clear than I originally thought.

btw as a point of explanation, I don't think any of this is being done by Cargo but by the built-in test harness, "libtest", which is why it isn't documented in Cargo. The way stdout/stderr capture works is a bit hacky and plugs directly into the print!`` and eprint!macros, not capturing anything written directly tostdoutandstderr. In https://github.com/rust-lang/testing-devex-team/issues/8 we are discussing ways of allowing anyone access to this machinery and capturing stdoutandstderr, not just print!andeprint!`.

Going ahead and moving this over to libtests repo

[KnorrFG]

I just realized, that I messed up the strings in the example. These lines:

    _ = writeln!(
        std::io::stderr(),
        "This should REALLY go to stdout (bad test)"
    );

should of course have the string "This should REALLY go to stderr (bad test)" and the same for the good variation.
I'll write the expected outputs as if I hadn't made this mistake. (Sorry)

1. Just make eprintln actually go to stderr, so that the output looks like this:

$ cargo test --test foo
   Compiling testtest v0.1.0 (/tmp/testtest)
    Finished test [unoptimized + debuginfo] target(s) in 0.13s
     Running tests/foo.rs (/tmp/testtest/target/debug/deps/foo-9896c48b30738b26)

running 2 tests
This should go to stderr (bad test)
This should REALLY go to stderr (bad test)
This should go to stderr
This should REALLY go to stderr
test good ... ok
test bad ... FAILED

failures:

---- bad stdout ----
This should go to stdout (bad test)
thread 'bad' panicked at tests/foo.rs:17:5:
I am a failure
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    bad

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

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

2. Same as one, but additionally, also capture stderr by default, and then print it at the end:

$ cargo test --test foo
   Compiling testtest v0.1.0 (/tmp/testtest)
    Finished test [unoptimized + debuginfo] target(s) in 0.13s
     Running tests/foo.rs (/tmp/testtest/target/debug/deps/foo-9896c48b30738b26)

running 2 tests
test good ... ok
test bad ... FAILED

failures:

---- bad output ----
This should go to stdout (bad test)
This should go to stderr (bad test)
This should REALLY go to stderr (bad test)
thread 'bad' panicked at tests/foo.rs:17:5:
I am a failure
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    bad

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

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

With this solution, it would be nice to additionally have the arguments --nocapture-stderr and --nocapture-stdout

And the situation that caused this problem was the following: I have cli programs that print some stuff to stderr and some to stdout. I wrote an integration test that executes the programs, and captures their stdout streams, while just forwarding their stderr streams. Additionally, the test itself uses eprintln for debugging output. The stderr output of the programs ended up in between the test results report while the eprintln output of the test was missing. This was what caused me a lot of confusion.

[epage]

To be clear, are (1) and (2) alternative solutions you would expect to see?

And to put these two words

1. You would like to see stderr not captured

• I feel this is unlikely to happen. Reporting debug statements can make the output really noisy. We are also looking into dramatically changing how tests are run and reported, allowing for richer test reporting. Interjecting alternative output in the middle of all of that would mess that up.

2. You want to see stdout and stderr captured as well

• We are tracking that in Tests do not capture stdout() / stderr() #90785.

with an optional --nocapture-stderr and --nocapture-stdout as well. We would need a better understanding of the use case for specializing these flags to weigh this. In general, we are moving trying to reduce the minimum expected behavior of test harnesses and work to move functionality to cargo test. This makes me hesitant to add these flags to test harnesses (though cargo test can't implement this on its own). This is part of an effort to shift the focus towards custom test harnesses. This would mean that you could more easily have your own harness that does provide these flags though.

eprintln output of the test was missing

Missing or was captured and not reported because the test didn't fail? This is a
big distinction and we need to make sure we are clear on it.

[KnorrFG]

Yeah, I guess I have more or less the same issue as the person that opens the issue that you linked.

I would consider 1. a minimal solution, and 2. the better solution. The current state is that you actually don't capture stdout (as I just tested) or stderr. All you do is redirecting the output of the print and eprint macros.

The ideal state, in my opinion, would be to not fiddle with the macros, and just let them print to stderr and stdout as they are supposed to, and as everyone expects them to, and then actually capture stderr and stdout. Then you would have consistent behavior.

If you want to see the output of your program you can use --nocapture which should then lead to the test not capturing any stream. Optionally, you could add --nocapture-stderr for when you are only interested in seeing stderr and --nocapture-stdout for the other case. All of those tree options might be handy, depending on the test.

[epage]

If this is about #90785, then I'm inclined to close in favor of that.

should then lead to the test not capturing any stream. Optionally, you could add --nocapture-stderr for when you are only interested in seeing stderr and --nocapture-stdout for the other case. All of those tree options might be handy, depending on the test.

Thats an explanation of what they do. I'm looking for use cases to understand why someone would need to specifically not capture only one stream.

[KnorrFG]

The use case depends on the test. If you write an integration test that calls multiple other programs, and that has a bug itself, sometimes you might be interested in the program's debug output, which typically goes to stderr. Sometimes you might be interested in the programs' stdout, an example might be seeing some hashes that md5sum prints to stdout. Sometimes you might want to see both at the same time.

Also, #90785 is only about tests not capturing stdout. This is additionally about tests not capturing stderr, and tests redirecting print and eprint, and about the fact that this is undocumented.

[epage]

I've updated the title for #90785.