Open popzxc opened 5 years ago
I propose that the methods for enabling and configuring this option be changed.
The option currently uses optflagopt
, which means that one must use =
to specify its parameter, e.g., --report-time=colored
. If one doesn't use =
, then the would-be parameter is interpreted as a filter, which is confusing. The difference is further jarring because no other libtest option uses optflagopt
. Finally, the current implementation of --report-time
does not produce an error when its parameter is not plain
or colored
.
I propose:
--report-time
, to enable the option, and --report-time-color
, to configure the optionoptopt
not optflagopt
, so that use of =
is optional when specifying the parameter--report-time-color
be always
, never
, and (if feasible) auto
(the default) (These choices seem more conventional than plain
and colored
.)--report-time-color
produce an error if its parameter is not among the three valid choicesDo others have opinions?
Note that cargo stabilized --timings
option. I think it'll be best if we name libtest option the same, i.e., rename --report-time
to --timings
.
Hoping this can get released to stable soon now that -Zunstable-options --report-time
no longer works on stable rust version. 😢
I was trying this out to focus on some slow tests.
One small feedback: according to ehuss in https://github.com/rust-lang/rust/issues/115989 the times are measured in milliseconds, but the doc https://doc.rust-lang.org/beta/unstable-book/compiler-flags/report-time.html and help strings don't specify the units.
However, beyond that, I can see that --report-time
works, which is great, but --ensure-time
and the time-limiting vars don't seem to work on integration tests?
With rustc 1.76.0-nightly (d86d65bbc 2023-12-10)
on 98d502b639
of https://github.com/sourcefrog/cargo-mutants:
; env RUST_TEST_TIME_UNIT=50,100 cargo +nightly test -- -Zunstable-options --report-time --ensure-time
Finished test [unoptimized + debuginfo] target(s) in 0.05s
Running unittests src/main.rs (target/debug/deps/cargo_mutants-a5abd64a2826343e)
running 78 tests
test console::test::test_duration_minutes_seconds ... ok <0.000s>
test fnvalue::test::box_usize_replacement ... ok <0.000s>
test fnvalue::test::box_unrecognized_type_replacement ... ok <0.000s>
...
test output::test::rotate ... FAILED (time limit exceeded) <0.102s>
test visit::test::expected_mutants_for_own_source_tree ... FAILED (time limit exceeded) <0.180s>
Great, that failed as it should have.
But on an integration test:
; env RUST_TEST_TIME_INTEGRATION=50,100 RUST_TEST_TIME_UNIT=50,100 cargo +nightly test --test cli -- -Zunstable-options --report-time --ensure-time
Finished test [unoptimized + debuginfo] target(s) in 0.05s
Running tests/cli/main.rs (target/debug/deps/cli-d36846210cc3addb)
running 97 tests
...
test jobs::jobs_option_accepted ... ok <9.147s>
test mutants_causing_tests_to_hang_are_stopped_by_manual_timeout ... ok <11.344s>
test well_tested_tree_finds_no_problems ... ok <16.703s>
test well_tested_tree_quiet ... ok <16.651s>
Even the tests that take much longer than either limit don't fail, and they aren't colored or highlighted either.
I've been trying RUST_TEST_TIME_INTEGRATION
and it's not working.
@sourcefrog @alejandrodnm
I tested it with the most recent compiler and it worked for me.
> cargo +nightly --version
cargo 1.78.0-nightly (ccc84ccec 2024-02-07)
> tree -I target
.
├── Cargo.lock
├── Cargo.toml
├── src
│  └── lib.rs
└── tests
└── example.rs
> cat tests/example.rs
#[test]
fn integration_test_fast() {
std::thread::sleep(std::time::Duration::from_millis(12))
}
#[test]
fn integration_test_slow() {
std::thread::sleep(std::time::Duration::from_millis(1234))
}
#[test]
fn integration_test_very_slow() {
std::thread::sleep(std::time::Duration::from_millis(12345))
}
> env RUST_TEST_TIME_INTEGRATION=50,100 RUST_TEST_TIME_UNIT=50,100 cargo +nightly test --test example -- -Zunstable-options --report-time --ensure-time
Finished test [unoptimized + debuginfo] target(s) in 0.00s
Running tests/example.rs (target/debug/deps/example-cc2e736b09617b55)
running 3 tests
test integration_test_fast ... ok <0.012s>
test integration_test_slow ... FAILED (time limit exceeded) <1.234s>
test integration_test_very_slow ... FAILED (time limit exceeded) <12.345s>
failures (time limit exceeded):
failures (time limit exceeded):
integration_test_slow
integration_test_very_slow
test result: FAILED. 1 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 12.35s
error: test failed, to rerun pass `--test example`
I suggest creating an issue with a minimal example. If you mention me, I'll dig into it.
Note that cargo stabilized
--timings
option. I think it'll be best if we name libtest option the same, i.e., rename--report-time
to--timings
.
The --timings
option of cargo is a rather complicated feature, while the --report-time
option of libtest simply add the execution time to the existing output. How about removing the --report-time
option and print the execution time by default? IMO this information provides valuable feedback most of the time and there are almost no drawbacks.
@jakoschiko I made a small reproduction similar to yours and it works as expected:
; env RUST_TEST_TIME_INTEGRATION=50,100 RUST_TEST_TIME_UNIT=50,100
cargo +nightly test --test cli -- -Zunstable-options --report-time --ensure-time
Compiling rust-report-time-repro v0.1.0 (/home/mbp/src/rust-report-time-repro)
Finished test [unoptimized + debuginfo] target(s) in 0.16s
Running tests/cli.rs (target/debug/deps/cli-c84202f49f5e5e6e)
running 1 test
test slow_test ... FAILED (time limit exceeded) <10.000s>
failures (time limit exceeded):
---- slow_test stdout ----
Slow test starting...
Slow test done.
failures (time limit exceeded):
slow_test
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 10.00s
However, when I try the exact same command in the cargo-mutants repo, it shows the times but it does not flag any failures. It's very surprising. I don't think mutants is doing anything especially strange to interfere with the normal working of the test harness.
; env RUST_TEST_TIME_INTEGRATION=50,100 RUST_TEST_TIME_UNIT=50,100 cargo +nightly test --test cli -- -Zunstable-options --report-time --ensure-time
Finished test [unoptimized + debuginfo] target(s) in 0.05s
Running tests/cli/main.rs (target/debug/deps/cli-7f3da6fc93e09d30)
running 106 tests
test colors::invalid_cargo_term_color_rejected_with_message ... ok <0.004s>
test completions_option_generates_something ... ok <0.021s>
...
test well_tested_tree_check_only ... ok <5.303s>
test log_file_names_are_short_and_dont_collide ... ok <7.172s>
test well_tested_tree_check_only_shuffled ... ok <5.593s>
test tree_with_child_directories_is_well_tested ... ok <6.808s>
test mutants_causing_tests_to_hang_are_stopped_by_manual_timeout ... ok <12.376s>
test well_tested_tree_finds_no_problems ... ok <19.610s>
test result: ok. 106 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 24.00s
As you can see some of these tests took much longer than the limit...
I wondered if it was something about running multiple threads in parallel throwing off the timing, so I tried with --test-threads 1
, but that did not fix it.
So, I don't know how to minimize it, but you should at least be able to reproduce this from the cargo-mutants public repo.
Can confirm, will investigate.
@sourcefrog Your repository doesn't have any integration tests :p
Usually an integration test has a path like this:
my_crate/tests/cli.rs // contains #[test] functions
In your case the path looks like this:
my_crate/tests/cli/main.rs // contains #[test] functions but no main function
This in neither documented here nor here. Surprisingly it does work, but the implementation of the #[test]
macro will emit the test type TestType::Unknown
:
if crate_path.ends_with("src") {
// `/src` folder contains unit-tests.
TestType::UnitTest
} else if crate_path.ends_with("tests") {
// `/tests` folder contains integration tests.
TestType::IntegrationTest
} else {
// Crate layout doesn't match expected one, test type is unknown.
TestType::Unknown
}
So technically RUST_TEST_TIME_INTEGRATION
does work as expected. Nevertheless, this is unsatisfactory.
Fascinating, well found. cargo metadata
and cargo test
see it as a test
target, but you're quite right it doesn't match what the docs specify,
which is that they need to be directly within tests
.
Tracks stabilization for the
report-time
andensure-test-time
libtest
options.