fix: Make test_runner::TestState::stdout optional to fix parsing cargo test json output

[duncanawoods]

For issue #18896 - cargo test json output does not include a stdout field if given the --nocapture flag.

RA only records the stdout for failed tests. It would be possible to move the stdout field to CargoTestMessage so that the user can inspect the stdout of passing tests too.

[ChayimFriedman2]

This will make failure printing not work, no? I prefer we capture stdout.

[HKalbasi]

This will make failure printing not work, no? I prefer we capture stdout.

I think capturing still works if user didn't explicitly add --nocapture flag.

[duncanawoods]

Yup, I don't think this affects anything besides fixing buggy parsing of cargo json output because the schema isn't right.

I have struggled to find the source for cargo's serialisation. Do unstable features only live in PRs of the tracking issue?

This is what I believe it it is:

/// Case-finished with failure event.
#[derive(Serialize, Deserialize, Debug, Eq, PartialEq)]
pub struct TestFailed {
    /// Test case name.
    pub name: String,
    /// Test's stdout
    pub stdout: Option<String>,
    /// Test failure mssage
    pub message: Option<String>,
    #[doc(hidden)]
    #[serde(skip)]
    __do_not_match_exhaustively: (),
}

rust-lang/rust#49359

https://github.com/crate-ci/escargot/pull/24/files

[ChayimFriedman2]

This will make failure printing not work, no? I prefer we capture stdout.

I think capturing still works if user didn't explicitly add --nocapture flag.

Yeah, I meant it'll break when the user did add --nocapture.

[duncanawoods]

There is an argument for making --nocapture the default because it's more like the test integration of other languages that pipe output straight to the Test Window:

1. with --nocapture RA stll receives the stdout and could gather it if it wanted. It's a choice to discard the output that isn't json.

2. with --nocapture we can see output during execution not just at the end e.g.

#[test]
fn my_integration_test() {
    println!("message a");
    std::thread::sleep(std::time::Duration::from_secs(3));
    println!("message b");
    std::thread::sleep(std::time::Duration::from_secs(3));
    println!("message c");
}

3. without it, If you kill a hanging test, all output is lost so you won't have any context for what happened

#[test]
fn my_integration_test() {
    println!("do the big thing...");
    std::thread::sleep(std::time::Duration::from_secs(2000));
}

4. for me, immediately seeing output in a window is much more natural than having to go via the test explorer to "peek" an error in an inlay

5. I use unit tests for basic inspection to orient myself around new systems/libraries e.g. printing out configuration or file contents or packets etc. so I value seeing the output of passing tests too

Anyway... not the goal of this quick fix!

[HKalbasi]

Is it possible to detect which output belongs to which test when running multiple tests using --no-capture?

[duncanawoods]

It's possible but not without undesirable trade-offs e.g.

1. Double-running

I think it's basically a bug/oversight that cargo test json loses output with --nocapture. I can't see any justification for it. It's been raised in the tracking issue so I hope it will be addressed before it's stabilised.

The workaround that user does is to run a test twice: once for humans and then again for the json reports:

rust-lang/rust#49359 (comment)

2. Debug-info

You can match assertion failures to tests because they are panics that produce a stack-trace with RUST_BACKTRACE=1. The test will be the 3rd frame from bottom. However, the default settings for release builds won't include the debug-info required for backtraces.

thread 'time::timestamp::tests::set_time' panicked at crates/xxxx/src/time/timestamp.rs:880:9:
assertion failed: `(left == right)`

Diff < left / right > :
<2000-01-01T11:11:09.008Z
>2000-01-01T11:10:09.008Z


stack backtrace:
   0: rust_begin_unwind
             at /rustc/9fc6b43126469e3858e2fe86cafb4f0fd5068869/library/std/src/panicking.rs:665:5
   1: core::panicking::panic_fmt
             at /rustc/9fc6b43126469e3858e2fe86cafb4f0fd5068869/library/core/src/panicking.rs:76:14
   2: xxxx::time::timestamp::tests::set_time
             at ./src/time/timestamp.rs:880:9
   3: xxxx::time::timestamp::tests::set_time::{{closure}}
             at ./src/time/timestamp.rs:878:18
   4: core::ops::function::FnOnce::call_once
             at /home/duncan/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
   5: core::ops::function::FnOnce::call_once
             at /rustc/9fc6b43126469e3858e2fe86cafb4f0fd5068869/library/core/src/ops/function.rs:250:5

3. Single-threading

You can't match non-panic stdout to tests in multi-threaded mode but with --test-threads 1, you can. The stdout will reliably appear between the start/finish json messages e.g.

{ "type": "test", "event": "started", "name": "time::timestamp::tests::test_math" }
test_math
{ "type": "test", "name": "time::timestamp::tests::test_math", "event": "ok" }

Single threaded could be slower than running a test suite twice so... eh.

4. Custom-threading

The threading issue could be solved by RA running multiple single-test cargo test threads so that the output doesn't get interleaved.

5. Custom Test Harness

One of the reasons cargo test arguments/output is so tricky is that it's using plug-in test runners. It might make sense for RA to have a thin wrapper harness to better support GUI integration:

a) custom test harness

• libtest-mimic looks to be the the starting point for a thin wrapper
  • https://docs.rs/libtest-mimic/latest/libtest_mimic/
• ironically it can't do anything with output capturing because of libtest
  • Capture output by default LukasKalbertodt/libtest-mimic#9

b) cargo-nextest

• has the "next generation test harness" already solved this?
  • no, turns out that their --nocapture switches to single-threaded mode like above
  • https://nexte.st/docs/reporting/

[duncanawoods]

Conclusion

However, I don't think this matters!

For me, the "run multiple tests" and "view full live test output" use-cases are separate.

My workflow would be satisfied by only using --nocapture when running a single test. When I run tests at the module/crate/workspace level I'm generally not interested in live output or the stdout of passing tests etc.

The full live test output is much more of a requirement/benefit when drilling-down and working on a specific test so I would personally choose to:

• default to --nocapture for single test runs
• default to no --nocapture for multi-test runs

It would be possible to implement an optional live test output for multi-test runs feature with one of the work-arounds (or just accept the json lacks the output) but probably not worth the effort.

[HKalbasi]

So I'm inclined to merge this PR to prevent server panic, and defer future work (which I guess also needs some work in cargo) to future PRs. @ChayimFriedman2 what do you think?

[ChayimFriedman2]

I don't have a strong opinion.