Repository navigation
Doctest execution should report discovery and compilation time #144270
Description
Consider the following output from running doctests:
$ time cargo test -p all-is-cubes-base --doc
Finished `test` profile [optimized + debuginfo] target(s) in 0.06s
Doc-tests all_is_cubes_base
running 60 tests
test all-is-cubes-base/src/math.rs - math::notnan (line 60) ... ok
test all-is-cubes-base/src/math/aab.rs - math::aab::Aab::round_up_to_grid (line 331) ... ok
[...]
test all-is-cubes-base/src/resolution.rs - resolution::Resolution::log2 (line 70) ... ok
test result: ok. 60 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
running 4 tests
test all-is-cubes-base/src/math.rs - math::notnan (line 76) - compile fail ... ok
test all-is-cubes-base/src/math.rs - math::notnan (line 91) - compile fail ... ok
test all-is-cubes-base/src/math.rs - math::notnan (line 69) - compile fail ... ok
test all-is-cubes-base/src/math.rs - math::notnan (line 83) - compile fail ... ok
test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.55s
real 0m10.268s
user 0m6.745s
sys 0m6.373sThe wall-clock time taken to run this test command is 10 s. The reported time to run these tests is 0.06 s + 0.01 s + 1.55 s, which only adds up to 1.62 s — the time spent discovering and compiling the doctests is not counted and reported. I believe this is a “diagnostic bug” of sorts — information is being omitted which misleads the user about the performance of their project’s test suite (until they carefully watch it progress in real time).
I believe this is caused by merged doctests, in that if I add ```standalone_crate to a doctest, it moves down to the second section and increases the reported time. (But, of course, that also increases the total time needed, so it does not help someone who wishes to improve performance of their test suite.)
It would be ideal if the compilation time was reported separately from the execution time (except for compile-fail tests) so the test author can direct their attention to the right part of the problem. However, it seems that would require either expanding libtest’s OutputFormatter trait or writing output outside of it (to stderr?).
Version
rustdoc 1.88.0 (6b00bc3 2025-06-23)
@rustbot label +A-doctests +A-libtest +T-rustdoc +T-testing-devex
Metadata
Metadata
Assignees
Labels
Type
Projects
- Status
Activity
GuillaumeGomez commentedon Jul 21, 2025
The origin of this bug is because rustdoc uses
libtestwhich doesn't compile test, just run them, and therefore doesn't take into account the compilation time. I suppose we can provide this time to the lib.kpreid commentedon Jul 21, 2025
While merely including the compilation time would “fix the regression”, I believe that it would be highly valuable to report the compilation time separately, so that users can distinguish “this doctest takes too long to compile” from “this doctest takes too long to run”, which are very different problems.
GuillaumeGomez commentedon Jul 21, 2025
That also makes the fix a lot simpler so definitely approve this approach. 😈
Rollup merge of rust-lang#144308 - GuillaumeGomez:merged-doctest-time…
Unrolled build for #144308
Rollup merge of #144308 - GuillaumeGomez:merged-doctest-times, r=lolb…
Rollup merge of #144308 - GuillaumeGomez:merged-doctest-times, r=lolb…