Is there a way to collect statistics from cargo test?

I am new to Rust, so I might not be using all the terms right and so on. Therefore, please, bear this in mind when answering.

I'm joining a team with a substantial Rust code base. We use cargo to build, test, and so on. We have lots of tests, which (collectively) take a long time to run. Of course, most run fast. I'd like to identify the slow ones. Does cargo test have a feature that does this? If not, seems it would be fairly easy to look at the output of cargo test to capture the information that I'm interested in, but I don't want to re-invent that wheel if there is already a good solution out there.

On nightly compilers, you can use some unstable flags to get these statistics.

Passing the unstable --report-time to the test executable makes it output the time it took for each test to run:

$ cargo +stable test -- -Z unstable-options --report-time
    Finished test [unoptimized + debuginfo] target(s) in 0.00s
     Running target/debug/deps/numerals-1da2b04c985a7342

running 5 tests
test roman::test::value_checked_err_on_large ... ok <0.000s>
test roman::test::value_panic_on_large ... ok <0.000s>
test roman::test::test_big_numbers ... ok <0.002s>
test bt::test::test_many_numbers ... ok <0.009s>
test roman::test::test_many_numbers ... ok <0.023s>

test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.02s

   Doc-tests numerals

running 5 tests
test src/roman.rs - roman (line 9) ... ok <0.249s>
test src/roman.rs - roman (line 38) ... ok <0.257s>
test src/roman.rs - roman (line 55) ... ok <0.269s>
test src/roman.rs - roman (line 72) ... ok <0.303s>
test src/roman.rs - roman (line 23) ... ok <0.318s>

test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.32s

You can combine the unstable --format json and the --report-time flags to have the test executable output as structured JSON that contains the execution time of each test. Running cargo test -- -Z unstable-options --report-time --format json 2> /dev/null on the same crate gives:

$ cargo test -- -Z unstable-options --report-time --format json 2> /dev/null
{ "type": "suite", "event": "started", "test_count": 5 }
{ "type": "test", "event": "started", "name": "bt::test::test_many_numbers" }
{ "type": "test", "event": "started", "name": "roman::test::test_big_numbers" }
{ "type": "test", "event": "started", "name": "roman::test::test_many_numbers" }
{ "type": "test", "event": "started", "name": "roman::test::value_checked_err_on_large" }
{ "type": "test", "event": "started", "name": "roman::test::value_panic_on_large" }
{ "type": "test", "name": "roman::test::value_checked_err_on_large", "event": "ok", "exec_time": 0.00002701 }
{ "type": "test", "name": "roman::test::value_panic_on_large", "event": "ok", "exec_time": 0.000070299 }
{ "type": "test", "name": "roman::test::test_big_numbers", "event": "ok", "exec_time": 0.0014721 }
{ "type": "test", "name": "bt::test::test_many_numbers", "event": "ok", "exec_time": 0.009415822 }
{ "type": "test", "name": "roman::test::test_many_numbers", "event": "ok", "exec_time": 0.019445221 }
{ "type": "suite", "event": "ok", "passed": 5, "failed": 0, "allowed_fail": 0, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": 0.01973012 }
{ "type": "suite", "event": "started", "test_count": 5 }
{ "type": "test", "event": "started", "name": "src/roman.rs - roman (line 23)" }
{ "type": "test", "event": "started", "name": "src/roman.rs - roman (line 38)" }
{ "type": "test", "event": "started", "name": "src/roman.rs - roman (line 55)" }
{ "type": "test", "event": "started", "name": "src/roman.rs - roman (line 72)" }
{ "type": "test", "event": "started", "name": "src/roman.rs - roman (line 9)" }
{ "type": "test", "name": "src/roman.rs - roman (line 9)", "event": "ok", "exec_time": 0.25434107 }
{ "type": "test", "name": "src/roman.rs - roman (line 72)", "event": "ok", "exec_time": 0.25587009 }
{ "type": "test", "name": "src/roman.rs - roman (line 55)", "event": "ok", "exec_time": 0.28541328 }
{ "type": "test", "name": "src/roman.rs - roman (line 38)", "event": "ok", "exec_time": 0.304906301 }
{ "type": "test", "name": "src/roman.rs - roman (line 23)", "event": "ok", "exec_time": 0.314071325 }
{ "type": "suite", "event": "ok", "passed": 5, "failed": 0, "allowed_fail": 0, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": 0.314348062 }

Each line is a single compilation event, as structured JSON. You could parse the data to determine which tests have the longest exec_time fields.

Is there a way to collect statistics from cargo test?

Related

Recent Posts