stop spraying numbers to stdout during test runs #892
Conversation
|
I wanted to capture a bit more of the debugging here. I noticed the spew of output and recognized as coming from this test. I found it surprising because I deliberately wrote this output to stdout so that it would be captured in the normal case. Once I convinced myself it really was trying to write to stdout and it wasn't being captured, I tried reproducing it with a little more information using this test program: fn main() {
doit();
}
fn doit() {
let t = term::stdout();
if let Some(mut term) = t {
eprintln!("stdout found");
term.fg(term::color::GREEN).unwrap();
write!(term, "writing this to stdout terminal!\n").unwrap();
term.reset().unwrap();
term.flush().unwrap();
} else {
eprintln!("no stdout found");
}
}
#[cfg(test)]
#[test]
fn test_doit() {
doit();
}This way, the test code can be run as a binary or a unit test. As a program, it works the way I expect: If you redirect stdout or stderr, you’re left with whatever you didn’t redirect in your terminal (as you’d expect): You can redirect stdout to a file, and we’ll see that the output we wrote to the "terminal" is there, escape sequences and all: Okay, so term gives you back a terminal interface for stdout regardless of whether it’s a real terminal. What about as a unit test? If we use and the individual pieces go where you (might) expect: Sure enough: if you don’t use --nocapture, you still get the terminal output! Even though you don’t usually get stdout from tests without --nocapture. My first thought was that maybe And the I modified my test program to print some stuff to stdout before and after the write to the terminal, so it looked like this: eprintln!("println to stderr (stdout found)");
println!("println to stdout (before)");
term.fg(term::color::GREEN).unwrap();
write!(term, "terminal write to stdout\n").unwrap();
term.reset().unwrap();
term.flush().unwrap();
println!("println to stdout (after)");That has the same behavior! I found this pretty surprising. I also modified the test program to sleep for 60 seconds, ran But that's the case. When the test runner runs things in the same process (which I think is the normal mode), it uses this hidden API in std: That API is implemented here: It appears to cause output from print/eprint and friends within the calling thread to be redirected to some other drain. Sure enough, the behavior reproduces even with this program, with no This produces: I think this explains all the observations. The summary is that under normal operation (i.e., without |
|
Not surprisingly, I'm not the first person to run into this: rust-lang/rust#12309 |
After #832, a regular
cargo testincludes junk emitted by the "unauthorized" test. Here's what it looks like:After a lot of digging, I found that under normal conditions (i.e., without --nocapture), the built-in test runner apparently only redirects output from the print/eprint family. It does not redirect all of stdout -- and in particular it does not redirect writes made with
write!. As a result, we were spraying these characters to stdout even when--nocapturewasn't specified.After this change:
But you still get the output with
--nocapture: