Feature Request: Show build durations using sphinx.ext.duration

[pllim]

Details

• Read the Docs project URL: https://readthedocs.org/projects/astropy/
• Build URL (if applicable): https://readthedocs.org/projects/astropy/builds/12314499/
• Read the Docs username (if applicable): pllim

This is a follow-up from #7648 (comment) .

cc @saimn and @humitos

Expected Result

When sphinx.ext.duration (which has been available since Sphinx 2.4 and we are using 3.x) is enabled by adding it to extensions list in conf.py, we expect an output like this in the build log:

====================== slowest reading durations =======================
16.173 coordinates/index
14.260 visualization/wcsaxes/ticks_labels_grid
12.112 visualization/rgb
11.582 visualization/wcsaxes/overlays
9.496 timeseries/index
7.912 stats/ripley
6.881 visualization/wcsaxes/slicing_datacubes
...
1.543 modeling/example-fitting-line
1.494 timeseries/io

Actual Result

"slowest reading durations" isn't shown. I don't have that commit to prove this anymore, but I will recreate it and link it back here. See astropy/astropy#11028

[pllim]

Update: I added relevant RTD log above, as requested.

[humitos]

Hi @pllim! I did a quick test isolating this and I'm not sure that the output of sphinx.ext.duration is not shown because of RTD.

This build, https://readthedocs.org/projects/test-builds/builds/12324199/, shows:

====================== slowest reading durations =======================
0.075 index
0.026 conf
0.002 contents

in the output of the sphinx-build command that Read the Docs executed. This is the repository/branch that I used to produce that output: https://github.com/readthedocs/test-builds/tree/sphinx.ext.duration.

[humitos]

@pllim is it possible that Astropy is doing "something weird" (?) inside the conf.py or somewhere that makes the output of sphinx-build to be different and not show the sphinx.ext.duration? maybe it changes stdout to something else? 🤔

[pllim]

Interesting. Thanks for looking into this! We will investigate and get back to you.

[pllim]

Well, don't have to remove that label so soon, bot.

[pllim]

Yeah, you are right. Maybe it is something in astropy. Works in spacetelescope/synphot_refactor#286 (https://readthedocs.org/projects/synphot/builds/12326198/):

...
build succeeded.

The HTML pages are in _build/html.
Updating searchtools for Read the Docs search... 
====================== slowest reading durations =======================
4.265 synphot/spectrum
1.505 synphot/bandpass
1.498 api/synphot.blackbody.BlackBody1D
1.352 synphot/tutorials
1.132 index

Thank you for your help!

[saimn]

Hmm weird, since it works locally (for astropy). Not sure what could cause a difference on RTD.

[pllim]

For astropy, I tried removing some extensions to see but all I got was more and more warnings and still no duration outputs. 🤷