Skip to content

libtest: Add --report-time flag to print test execution time#64663

Merged
bors merged 2 commits intorust-lang:masterfrom
jakoschiko:report-time
Sep 25, 2019
Merged

libtest: Add --report-time flag to print test execution time#64663
bors merged 2 commits intorust-lang:masterfrom
jakoschiko:report-time

Conversation

@jakoschiko
Copy link
Copy Markdown
Contributor

Implements the flag --report-time to print the execution time of each executed (successful or failed) test.

Closes #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

Loading
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

merged-by-bors This PR was explicitly merged by bors. S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Report test case timing information

9 participants