[rustdoc] Display total time and compilation time of merged doctests #144308

GuillaumeGomez · 2025-07-22T14:03:37Z

Does it look good to you @kpreid?

rustbot · 2025-07-22T14:03:42Z

rustbot has assigned @notriddle.
They will have a look at your PR within the next two weeks and either review your PR or reassign to another reviewer.

Use r? to explicitly pick a reviewer

kpreid · 2025-07-22T14:57:17Z

Does it look good to you @kpreid?

This seems sufficient, in that it communicates the missing information, separately.

However, there is a way in which I predict it will be frequently confusing: there is no spatial or textual association of "merged doctests compilation took…" with which tests are the merged ones. A user wanting to know which doctests this refers to has to reason about what 'merged doctests' means and then, using that fact, figure out they must be the first group since the second group has compile-fail tests.

I strongly recommend that the report of compilation time should not be separated from the tests it refers to by unrelated tests.

When I initially imagined quickly adding this feature, I imagined putting the doctest compilation time at the top, corresponding to when it actually happens, and thus also adjacent to the merged tests. Another option would be to label the group of merged tests as merged, somehow.

GuillaumeGomez · 2025-07-22T15:00:16Z

You can have multiple merged doctests groups, so unless we show it for each group, I'm not sure it's really useful. It tells how much time it spent compiling merged doctests and the total time for all doctests.

kpreid · 2025-07-22T15:05:43Z

Ah, I see, I wasn't aware that there was a possibility of multiple groups. I don't have any further ideas. Thank you for working on this.

lolbinarycat · 2025-07-22T18:52:54Z

src/librustdoc/doctest.rs

+struct MergedDoctestTimes {
+    total_time: Instant,
+    compilation_time: Duration,
+    /// This field is used to keep track of how many merged doctests we (tried to) compile.
+    added_compilation_times: usize,
+}


Suggested change

struct MergedDoctestTimes {

total_time: Instant,

compilation_time: Duration,

/// This field is used to keep track of how many merged doctests we (tried to) compile.

added_compilation_times: usize,

}

struct DoctestTimes {

compilation_start: Instant,

/// Total time spent compiling all merged doctests

merged_compilation_time: Duration,

/// This field is used to keep track of how many merged doctests we (tried to) compile.

merged_doctest_count: usize,

}

Since this tracks time for standalone and merged doctests, I think these names would be more clear.

Also, is it possible for multiple merged doctest groups to get compiled in parallel? if so, that could cause some confusion due to the total time actually being shorter.

Not currently at least and I don't think we're planning to. That could potentially use too much resources.

I added the comments, however I didn't rename the type as it is only used for merged doctests and therefore didn't update the field name either.

the total time is the total time for all doctests, though??

Yes but it's only run in merged doctests context.

lolbinarycat · 2025-07-22T18:54:40Z

src/librustdoc/doctest.rs

+    fn display_times(&self) {
+        // If no merged doctest was compiled, then there is nothing to display.
+        if self.added_compilation_times > 0 {
+            println!("{self}");
+        }
+    }
+}
+
+impl fmt::Display for MergedDoctestTimes {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        write!(
+            f,
+            "all doctests ran in {:.2}s; merged doctests compilation took {:.2}s",
+            self.total_time.elapsed().as_secs_f64(),
+            self.compilation_time.as_secs_f64(),
+        )
+    }
+}


Shouldn't we still print the total compilation time, even if there are no merged doctests?

No because in this case, the numbers displayed by libtest are already accurate.

Some extra info: for standalone tests, libtest reports both compilation and run time as each doctest passed to libtest will call the doctest_run_fn which handles both.

hm, that's odd, that's what i thought initially, but the numbers in the screenshot simply don't add up for that to be the case. not sure what's happening here.

in any case, the comment explaining the rationale for ommitting all the output seems incomplete and mildly misleading.

lolbinarycat · 2025-07-22T19:13:01Z

src/librustdoc/doctest.rs

@@ -501,11 +548,12 @@ fn run_test(
    rustdoc_options: &RustdocOptions,
    supports_color: bool,
    report_unused_externs: impl Fn(UnusedExterns),
-) -> Result<(), TestFailure> {
+) -> (Duration, Result<(), TestFailure>) {


There should be a comment explaining that this is the time taken for compilation, not the total time overall.

Indeed, gonna add some comments.

lolbinarycat · 2025-07-22T19:14:27Z

src/librustdoc/doctest.rs

+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        write!(
+            f,
+            "all doctests ran in {:.2}s; merged doctests compilation took {:.2}s",


Suggested change

"all doctests ran in {:.2}s; merged doctests compilation took {:.2}s",

"all doctests compiled in {:.2}s; merged doctests compilation took {:.2}s",

misleading string, this only measures compilation time

Euh no. It measures the total time.

i got confused by the inconsistencies of the times in the screenshot, i think.

lolbinarycat · 2025-07-22T19:44:35Z

src/librustdoc/doctest.rs

@@ -1071,7 +1120,7 @@ fn doctest_run_fn(
        no_run: scraped_test.no_run(&rustdoc_options),
        merged_test_code: None,
    };
-    let res =
+    let (_, res) =


Is there a reason we're not also tracking this, so we can report (time compiling standalone tests, time compiling merged tests)?

I believe doctests are run with some level of parallelism, so currently we would be reporting the total absolute wall clock time for the total compilation time, but for merged doctests, we're reporting the sum of the amount of time each thread spent compiling. This inconsistency could over-report the impact of merged doctests.

Also, if parallelism is involved, then I think perhaps a more useful metric for minimizing compilation time would be how long the longest test took.

rustbot assigned notriddle Jul 22, 2025

rustbot added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. T-rustdoc Relevant to the rustdoc team, which will review and decide on the PR/issue. labels Jul 22, 2025

lolbinarycat requested changes Jul 22, 2025

View reviewed changes

GuillaumeGomez added 2 commits July 23, 2025 19:49

Display total time and compilation time of merged doctests

f457600

Update rustdoc ui tests

d0ec770

GuillaumeGomez force-pushed the merged-doctest-times branch from a3d520c to d0ec770 Compare July 23, 2025 17:49

	"all doctests ran in {:.2}s; merged doctests compilation took {:.2}s",
	"all doctests compiled in {:.2}s; merged doctests compilation took {:.2}s",

[rustdoc] Display total time and compilation time of merged doctests #144308

Are you sure you want to change the base?

[rustdoc] Display total time and compilation time of merged doctests #144308

Conversation

GuillaumeGomez commented Jul 22, 2025 • edited by rustbot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

rustbot commented Jul 22, 2025

Uh oh!

kpreid commented Jul 22, 2025

Uh oh!

GuillaumeGomez commented Jul 22, 2025

Uh oh!

kpreid commented Jul 22, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lolbinarycat Jul 23, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

GuillaumeGomez commented Jul 22, 2025 •

edited by rustbot

Loading

lolbinarycat Jul 23, 2025 •

edited

Loading