Report test case timing information #46610
Labels
A-libtest
Area: #[test] related
C-feature-request
Category: A feature request, i.e: not implemented / a PR.
Comments
|
Thanks @vitiral, you're right that I never got around to opening an issue. |
pietroalbini
added
C-feature-request
|
What is the plan on this? |
|
wow, crazy this doesn't exist is there a workaround in the meantime to find slow tests? |
Centril
added a commit
to Centril/rust
that referenced
this issue
Sep 23, 2019
libtest: Add --report-time flag to print test execution time Implements the flag `--report-time` to print the execution time of each executed (successful or failed) test. Closes rust-lang#46610 # Example `cargo test -- --report-time` produces the following output to stdout: ``` running 6 tests test tests::ignore ... ignored test tests::noop ... ok 0.000s test tests::should_panic ... ok 0.000s test tests::panic_after_10millis ... FAILED 0.010s test tests::sleep_100millis ... ok 0.100s test tests::sleep_10secs ... ok 10.001s failures: ---- tests::panic_after_10millis stdout ---- thread 'tests::panic_after_10millis' panicked at 'foo', src\lib.rs:31:9 failures: tests::panic_after_10millis test result: FAILED. 4 passed; 1 failed; 1 ignored; 0 measured; 0 filtered out ``` `cargo test -- --report-time -Z unstable-options --format=json` produces the following output to stdout: ``` { "type": "suite", "event": "started", "test_count": 6 } { "type": "test", "event": "started", "name": "tests::ignore" } { "type": "test", "event": "started", "name": "tests::noop" } { "type": "test", "event": "started", "name": "tests::panic_after_10millis" } { "type": "test", "event": "started", "name": "tests::should_panic" } { "type": "test", "name": "tests::ignore", "event": "ignored" } { "type": "test", "event": "started", "name": "tests::sleep_100millis" } { "type": "test", "name": "tests::noop", "event": "ok", "exec_time": "0.000s" } { "type": "test", "event": "started", "name": "tests::sleep_10secs" } { "type": "test", "name": "tests::should_panic", "event": "ok", "exec_time": "0.000s" } { "type": "test", "name": "tests::panic_after_10millis", "event": "failed", "exec_time": "0.010s", "stdout": "thread 'tests::panic_after_10millis' panicked at 'foo', src\\lib.rs:31:9\n" } { "type": "test", "name": "tests::sleep_100millis", "event": "ok", "exec_time": "0.101s" } { "type": "test", "name": "tests::sleep_10secs", "event": "ok", "exec_time": "10.000s" } { "type": "suite", "event": "failed", "passed": 4, "failed": 1, "allowed_fail": 0, "ignored": 1, "measured": 0, "filtered_out": 0 } ``` `cargo test -- --report-time --logfile foo.log` produces the following logfile: ``` ignored tests::ignore ok tests::noop 0.000s ok tests::should_panic 0.000s failed tests::panic_after_10millis 0.010s ok tests::sleep_100millis 0.100s ok tests::sleep_10secs 10.001s ```
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
I would like to ask that a feature to output the runtime (in float seconds to 3 significant digits) of tests be added (at least as a flag) to help find which tests are taking a long time. It would be parituclarily useful in build systems where the user might not have as much information (i.e. is not watching the tests run).
We could also consider outputting the "system" time as well as the "real" time.
Some possible flags:
--report-time--report-timing---report-durationBut I would be pretty open to anything.
Preferably we would just do this by default (with no flag) but my bet is that enough people depend on the stdout of
cargo testthat that would (almost) be considered a breaking change.The text was updated successfully, but these errors were encountered: