`cargo test` doesn't capture print from threads

[kpcyrd]

I've filed this bug in rust-lang/cargo but I'm afraid rust-lang/rust is the correct repo for this.

I ran the tests for one of my crates that uses threads in its example code. I've noticed it printed some lines to stdout, even though --nocapture wasn't set, but not all of them. It appears that text printed from new threads are not correctly captured, I think this is not intended.

Reproduce

#[cfg(test)]
mod tests {
    use std::thread;
    use std::time::Duration;

    #[test]
    fn it_works() {
        thread::spawn(move || {
            println!("request: {:?}", 123);
        });

        thread::sleep(Duration::from_secs(1));
        println!("response: {:?}", 456);
    }

Output

running 2 tests
request: 123
test tests::it_works ... ok
[...]

Meta

rustc --version --verbose:

rustc 1.17.0
binary: rustc
commit-hash: unknown
commit-date: unknown
host: x86_64-unknown-linux-gnu
release: 1.17.0
LLVM version: 4.0

[retep998]

set_print (which is what tests use to capture stdout) modifies a thread local, so it only captures output on that exact thread. If you spawn a new thread, it starts with fresh thread locals and so stdout isn't captured.

[mathstuf]

In my tests, I use log in my code and the the tests set up a simple println! logger when they run. Is there some way to have the log implementation send the output to the right place?

[dtolnay]

I would be interested in seeing a fix for this in a PR.

[mathstuf]

It'd be nice if there were some way to ask the current test "what print sink are you using?" so that it can pass them down to any spawned threads. That would at least work for "manual" threads. It wouldn't work for things like Rayon (AFAIK).

[azriel91]

The following issues appear to be duplicates (or at least, related):

• libtest - capture stderr from tests #40298
• libtest captures stdout&stderr only on first thread. #31983
• Capturing stdout from test code is inconsistent #12309