Add an option to know which files slow down the build

[saimn]

Is your feature request related to a problem? Please describe.

While investigating a bit why astropy's documentation build is slow (astropy/astropy#7080), I wanted to know which RST files take the most time to parse.
So I quickly added some code in sphinx to report the slowest files : https://gist.github.com/saimn/bd275de04bfdb975c1781b0f666919de
This also include the memory usage, but this is probably not necessary (we had a file taking several Gb of memory because of a bug in matplotlib's hist function).

Describe the solution you'd like

It would be handy to have an option to report the N slowest files, similar to pytest's --durations option.

My hack above only reports the read (and parse) time, which I think is the most interesting, I'm not sure if the same would be useful for the other stages?

[tk0miya]

+0: interesting. I can accept if this also supports parallel build.

[saimn]

Supporting parallel builds seems more difficult since this would mean passing the times to the parent process through env, merging this etc. It is certainly doable, but I'm not sure if this is worth it.

This is what I have now: master...saimn:read-time
And what it looks like below. Tell me what you think, if this seems useless I'm happy to spend my time on something else ;).

sphinx ❯ LANG=C sphinx-build --read-duration 5 . _build/html
Running Sphinx v2.0.1
making output directory... done
building [mo]: targets for 0 po files that are out of date
building [html]: targets for 72 source files that are out of date
updating environment: 72 added, 0 changed, 0 removed
reading sources... [100%] usage/theming                                                        
5 slowest files:
changes : 1.66 sec.
usage/builders/index : 1.01 sec.
usage/configuration : 0.85 sec.
extdev/appapi : 0.51 sec.
extdev/index : 0.49 sec.
looking for now-outdated files... none found
pickling environment... done
checking consistency... done
preparing documents... done
writing output... [100%] usage/theming                                                         
generating indices... genindex py-modindex
highlighting module code... [100%] sphinxcontrib.websupport.storage                            
writing additional pages... index search opensearch
copying images... [100%] _static/themes/sphinx_rtd_theme.png                                   
copying downloadable files... [100%] usage/extensions/example_numpy.py                         
copying static files... done
copying extra files... done
dumping search index in English (code: en) ... done
dumping object inventory... done
build succeeded.

The HTML pages are in _build/html.

[tk0miya]

I just made an simple extension to measure reading durations. It measures the duration between two events source-read and doctree-read. It is almost same as reading duration. It seems working fine on parallel build also.

I'm wondering which bundled or separated package is better for this extension.
@shimizukawa any idea?

[saimn]

Nice! Initially I thought about making an extension but could not find the appropriate events.

[tk0miya]

Oh, sorry. this is an example of the extension.
https://gist.github.com/tk0miya/388f07da7bc13f9d2b593d7110c8aa8a

[shimizukawa]

I think it would be better if it is bundled to the Sphinx package.
It's useful for large document owners and extension developers.

[tk0miya]

I added sphinx.ext.duration in #6922 . It will be released in 2.4.0.
Thank you for reporting!

[saimn]

Great, thanks!

[eine]

@tk0miya, in http://www.sphinx-doc.org/en/master/usage/extensions/duration.html it is said that this feature was new in v2.3. However, trying to use it with v2.3.1 produces the following error:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/sphinx/registry.py", line 475, in load_extension
    mod = import_module(extname)
  File "/usr/local/lib/python3.8/importlib/__init__.py", line 127, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 1014, in _gcd_import
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 973, in _find_and_load_unlocked
ModuleNotFoundError: No module named 'sphinx.ext.duration'

According to https://readthedocs.org/projects/sphinx/downloads/pdf/master/ (page 318) it was added in v2.4 not v2.3. This is coherent with your comment above. Should the web site be fixed?

/cc @Paebbels

[tk0miya]

Ah, you're right. It's my wrong. Fixed.