Full build with PDF is taking more than 24h

Today we're building 6 versions for 13 languages (that's 78 builds).

I'm doing some tests on my machine to get an idea:

An HTML build takes 55 s.
A full build (html + text + PDF A4 + PDF letter + epub + texinfo) takes around 21 min, composed of:
- 1 min for make html composed of:
  - 50 s for sphinx-build
  - 10 s of html archiving
- 40 s for make text
- 9 min for the A4 PDF build composed of:
  - 1 min for make latex PAPER=a4
  - 8 min for make all-pdf (in build/latex/) (less if run again, like 1 s if not removing PDFs, or 1 min after removing PDFs). Can be cut down to 6 min with -j 4.
- 8 min 30 for the letter PDF build, roughly similar to A4 unsurprisingly
- 1 min for the epub build
- 1 min 30 s for the texinfo build

So a complete rebuild should take ~27h (on my machine, the server may have a different CPU).

Building only the changed branches and languages, how does it sound?

I don't have much information about the server but here are some ideas:

We can store the commit hashes for each branch and language, and check if the head has changed, if changed we can clone and build.
If we already have all language repos cloned, and we do git pull everytime we build; we can instead git fetch in each repo and see if there are any changes, and if that's the case we can pull and build.

@JulienPalard

Additional question for @JulienPalard: Are non-bugfix and non-stable releases only rebuilt manually or is there a cron?

Are non-bugfix and non-stable releases only rebuilt manually or is there a cron?

EOL and security-fixes branches are only built manually, yes.

@JulienPalard

What do you think about the idea in general @JulienPalard?

I don't have much information about the server

The server stores a unique clone of cpython.
The server keeps all translation repositories.

(see the git_clone function in the script).

Building only the changed branches and languages, how does it sound?

Maybe, yes. But to do it cleanly we should only rebuild if the Doc/ directory changed, but doable and cheap as we keep the cpython clone.

Currently a git log shows that (for the Doc/ directory) changes are:

the main branch has many updates daily
the 3.11 branch has daily updates
the 3.10 branch has 3 updates per month
the 3.9 branch has 1 update per month

A change cpython side should trigger a rebuild of all languages for the given branch (while a change for a language should not trigger a rebuild for all branches: translation repo has a translation branch per cpython branch).

Translation side I expect less changes, except for a few crons like for python-docs-ja which synchronizes daily. Also changes are for a single branch so they invalidate a single cpython branch.

So instead of rebuilding 78 docs per day, just looking at the cpython side, we'd rebuild like 26 docs daily (main and 3.11) which should take like 9h.

About how to do this, we could store at build time the cpython commit sha and the translation commit sha in a file, and at build time call a dedicated function to check the shas against the repositories to see if a build is needed or not.

Seems doable.

@JulienPalard

@JulienPalard Someone opened an issue on Sphinx in order to know whether we could speed-up things on our side. I am not quite confident in that since most of the build time is actually the PDF build. It is possible to know why make all-pdf is so slow? is it only because there are a lot of pages to write? or is it because of the underlying language? (iirc, jp builds don't build with plain pdflatex).

Another possibility is to change the way the PDF are created. We (Sphinx) could technically add a builder which, instead of outputting LaTeX code, outputs some other kind of typesetting language that can still be converted to PDF faster than LaTeX.

@picnixz

Hi @picnixz, thanks for jumping in!

It is possible to know why make all-pdf is so slow?

I'm just a user of LaTeX, I don't know much. I know our biggest file is library.tex with 288k lines of LaTeX, generating a 11MB PDF file.

make all-pdf runs latexmk for each .tex files, which in turn runs xelatex. So I tried just running time latexmk -pdf -dvi- -ps- library.tex, it takes 1 min 16s (on the same laptop used for the timings in the first post). same timing for the underlying command: xelatex -recorder library.tex.

Those timings can be reproduced on a cpython clone after building latex file:

make -C Doc/build/latex/ clean
time make -C Doc/build/latex/ library.pdf  # 4 min 30s
time (cd Doc/build/latex; make clean; XINDYOPTS="-L english -C utf8 -M sphinx.xdy" latexmk -pdf -dvi- -ps- library.tex) # 4 min 13s
time (cd Doc/build/latex; xelatex -recorder library.tex`  # 1 min 16s

It reminds me of something about running it in a loop until the output does not changes..., which strace confirms:

$ grep bin/xelatex make.strace 
15622 1696969290.322763 execve("/usr/bin/xelatex", ["xelatex", "-recorder", "library.tex"], 0x55b2cfd2a5d8 /* 90 vars */) = 0
15719 1696969388.530816 execve("/usr/bin/xelatex", ["xelatex", "-recorder", "library.tex"], 0x5651c759b5d8 /* 90 vars */) = 0
15766 1696969471.969531 execve("/usr/bin/xelatex", ["xelatex", "-recorder", "library.tex"], 0x55ddc43a15d8 /* 90 vars */) = 0

Which also can be confirmed by reading the console log (I choose a smaller file to get readable output):

------------
Run number 1 of rule 'pdflatex'
------------
------------
Running 'xelatex   -recorder  "howto-cporting.tex"'
------------

[...]

Rule 'pdflatex':  Reasons for rerun
Changed files or newly in use/created:
  howto-cporting.aux
  howto-cporting.ind
  howto-cporting.out
  howto-cporting.toc

------------
Run number 2 of rule 'pdflatex'
------------
------------
Running 'xelatex   -recorder  "howto-cporting.tex"'
------------

Also noticed, from xelatex output:

LaTeX Warning: Label(s) may have changed. Rerun to get cross-references right.

Package rerunfilecheck Warning: File `library.out' has changed.
(rerunfilecheck)                Rerun to get outlines right
(rerunfilecheck)                or use package `bookmark'.

this is probably less than ideal.

I tried to use perf to get some insights about what's slow inside xetex, if I read this correctly that's the parsing of the input file that's slow, can be reproduced using:

sudo sysctl kernel.perf_event_paranoid=-1
sudo apt install texlive-binaries-dbgsym  # needs `deb https://deb.debian.org/debian-debug trixie-debug main`
time (cd Doc/build/latex/; make clean; perf record -F 1000 -g --call-graph dwarf -o perf.data xelatex -recorder library.tex)
(cd Doc/build/latex/; perf report --tui)

it looks like this:

-   80.59%     0.00%  xelatex    xetex                     [.] main                                               ▒
   - main                                                                                                         ▒
      - 80.54% mainbody                                                                                           ▒
         - 80.37% maincontrol                                                                                     ▒
            - 35.42% getxtoken                                                                                    ▒
               - 18.35% expand                                                                                    ▒
                  - 12.60% conditional                                                                            ▒
                     + 9.10% scanint                                                                              ▒
                     + 1.37% passtext                                                                             ▒
                  + 3.13% expand                                                                                  ▒
                    0.54% passtext                                                                                ▒
               - 14.03% macrocall                                                                                 ▒
                    6.20% getnext                                                                                 ▒
                    1.92% endtokenlist                                                                            ▒
               + 2.67% getnext                                                                                    ▒
            - 35.25% prefixedcommand                                                                              ▒
               - 29.63% zscantoks                                                                                 ▒
                  - 26.62% expand                                                                                 ▒
                     - 19.90% macrocall                                                                           ▒
                        - 10.50% getnext                                                                          ▒
                             3.33% endtokenlist                                                                   ▒
                          1.77% endtokenlist                                                                      ▒
                          0.63% getavail                                                                          ▒
                     + 5.68% conditional                                                                          ▒
                    1.87% getnext                                                                                 ▒
               + 3.12% zdoregistercommand                                                                         ▒
                 0.52% zeqdefine                                                                                  ▒
            + 3.87% measure_native_node                                                                           ▒
              0.86% unsave                                                                                        ▒
            + 0.60% zshipout                                                                                      ▒
            + 0.58% endgraf.part.0                                                                                ▒
              0.51% zbeginbox                                                                                     ▒

is it only because there are a lot of pages to write?

Probably yes, library.pdf is 2318 pages, or lots of latex to parse if my perf reading is good.

or is it because of the underlying language? (iirc, jp builds don't build with plain pdflatex).

Looking at the server logs, yes jp is slower than all the others. It takes like 1h30 while the other take like 30mn (for a full build of text, html, pdfs, ...). All builds are using xelatex while jp builds are using lualatex. As it's the only one I won't focus on this one.

Another possibility is to change the way the PDF are created. We (Sphinx) could technically add a builder which, instead of outputting LaTeX code, outputs some other kind of typesetting language that can still be converted to PDF faster than LaTeX.

It would be possible to build PDF using weasyprint.

It looks like a potential alternative for PDFs building is using Rinohtype. It provides a drop-in replacement for Sphinx PDF builder and is a direct PDF builder. Still in beta though.

Thank you very much for your report !

Now I'm a bit confused about these timings:

time make -C Doc/build/latex/ library.pdf # 4 min 30s
time (cd Doc/build/latex; make clean; XINDYOPTS="-L english -C utf8 -M sphinx.xdy" latexmk -pdf -dvi- -ps- library.tex) # 4 min 13s
time (cd Doc/build/html; xelatex -recorder library.tex` # 1 min 16s

Maybe I misunderstood, but why does the second command takes 4 min 13s but you told me it took 1min 16s? I also think the last command should be cd Doc/build/latex instead of cd Doc/build/html.

if I read this correctly that's the parsing of the input file that's slow

Yes, it's because of how LaTeX is structured with this token based approach + expansions. Depending on how expansions are done, it may enormously slow down the build. I am wondering whether breaking down library.tex into smaller pieces that are put together at the end would improve or not the timings.

In conclusion, I don't think we could do much except:

writing to another format than LaTeX in order to convert it to PDF (e.g., Typst) but I am not aware of any typesetting language as powerful as LaTeX. Also, if we were to include that, we'll need to add an extension for that (or ask the community to help us).
try to see if breaking down huge files may help or not.

By the way, how much is allocated to build the documentation on Python servers? because a straightforward solution is simply to allocate more resources and run everything in parallel (but again, funds are required and I don't know if the server is like a super-mega-huge-powerful server). In the end, if you need to rebuild 26 docs per day (assuming you can reduce from 70+), the you "simply" need a more powerful unit.

Now I'm a bit confused about these timings:

time make -C Doc/build/latex/ library.pdf # 4 min 30s
time (cd Doc/build/latex; make clean; XINDYOPTS="-L english -C utf8 -M sphinx.xdy" latexmk -pdf -dvi- -ps- library.tex) # 4 min 13s
time (cd Doc/build/html; xelatex -recorder library.tex` # 1 min 16s

Maybe I misunderstood, but why does the second command takes 4 min 13s but you told me it took 1min 16s?

That's because latexmk runs xelatex in a while True: loop until the output stabilizes. Looks like it had to run it 4 times to reach stabilization (I have a few paragraph in my last message about it, search for 'strace' and 'rerun').

I really don't know if there's a way to forge a latex file that necessitates less re-runs.

I also think the last command should be cd Doc/build/latex instead of cd Doc/build/html.

Probably just me manually fixing the commands for readability (and breaking them while doing so, haha).

That's because latexmk runs xelatex in a while True: loop until the output stabilizes

Ah sorry! yes I overlooked that (I was a bit confused actually because I assumed that the ~1min was the output of time). Now, the question is: is it possible to avoid using xelatex actually and only pdflatex?

Also, since it tells us "or use package bookmark", maybe this could solve the issue (though I don't know how). Nevertheless, yet another alternative is to run the latex command only once and check whether more compilation is needed (and not let latexmk decides by itself). I'm not sure whether the 4 runs are actually needed to solve all the references (in general, we need 2 reruns but here I'm wondering why we actually need 4).

Btw, I'm sorry but I cannot really reproduce it myself because I need to install fonts that I don't have (and move them around files + adding paths or so) (but since you've got everything running on your side + timings are for your machine, the comparison is more fair).

IIRC we use xetex instead of pdflatex for its unicode awareness.

Tried:

$ make -C build_root/cpython/Doc PYTHON=build_root/venv-3.11/bin/python SPHINXBUILD=build_root/venv-3.11/bin/sphinx-build BLURB=build_root/venv-3.11/bin/blurb VENVDIR=build_root/venv-3.11 'SPHINXOPTS=-D latex_engine=pdflatex -q' SPHINXERRORHANDLING= autobuild-stable

[...]

LaTeX Warning: Hyper reference `howto/regex:the-backslash-plague' on page 6 und
efined on input line 816.

[6]

! LaTeX Error: Unicode character ſ (U+017F)
               not set up for use with LaTeX.

See the LaTeX manual or LaTeX Companion for explanation.
Type  H <return>  for immediate help.
 ...                                              
                                                  
l.962 Latin small letter dotless i), ‘ſ
                                          ’ (U+017F, Latin small letter lo...

?

Since #171 has been merged, there has been a build taking 13.6 hours. That's better, probably still room for enhancements.

I changed the build cron so it starts hourly, so instead of doing nothing for 24h-13.6h the script checks if there's something to build.

In the logs here's what I see:

2023-10-27 04:56:30,401 INFO en/3.12: Nothing changed, no rebuild needed.
2023-10-27 04:56:31,868 INFO zh-tw/3.13: Should rebuild: new translations (from a4719a1e1605163e886fad5c3783bdac250f0db9 to f24fd11929f41176367f42559c62b808e7468b2d)
2023-10-27 06:15:32,386 INFO zh-cn/3.13: Should rebuild: new translations (from 99da58558f6c81e2808bbe85307f5d480c9ec096 to ef8a1e2bd3a47f9a5d21c7f6495d3f525f3c66e6)
2023-10-27 07:30:51,890 INFO uk/3.13: Nothing changed, no rebuild needed.
2023-10-27 07:30:52,196 INFO tr/3.13: Nothing changed, no rebuild needed.
2023-10-27 07:30:52,494 INFO pt-br/3.13: Nothing changed, no rebuild needed.
2023-10-27 07:30:52,804 INFO pl/3.13: Nothing changed, no rebuild needed.
2023-10-27 07:30:53,072 INFO ko/3.13: Nothing changed, no rebuild needed.
2023-10-27 07:30:53,989 INFO ja/3.13: Should rebuild: new translations (from 32e85a08b356b6faa3c5784f1d5bdea15ec2e4f4 to 260a16dd7cb834bcffe2bee64375f6e8d43f1b35)
2023-10-27 08:51:27,928 INFO it/3.13: Nothing changed, no rebuild needed.
2023-10-27 08:51:28,353 INFO id/3.13: Nothing changed, no rebuild needed.
2023-10-27 08:51:28,685 INFO fr/3.13: Nothing changed, no rebuild needed.
2023-10-27 08:51:29,262 INFO es/3.13: Nothing changed, no rebuild needed.
2023-10-27 08:51:29,363 INFO en/3.13: Nothing changed, no rebuild needed.
2023-10-27 09:07:07,306 INFO zh-tw/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:08,020 INFO zh-cn/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:08,501 INFO uk/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:08,992 INFO tr/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:09,540 INFO pt-br/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:09,947 INFO pl/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:10,255 INFO ko/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:11,250 INFO ja/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:11,512 INFO it/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:11,767 INFO id/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:12,113 INFO fr/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:12,820 INFO es/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:12,908 INFO en/3.11: Nothing changed, no rebuild needed.
2023-10-27 09:07:15,611 INFO zh-tw/3.12: Should rebuild: new translations (from a4719a1e1605163e886fad5c3783bdac250f0db9 to eaccd60ee755daee77d4fe24707c1a2ec6059bfb)
2023-10-27 09:49:24,057 INFO zh-cn/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:24,383 INFO uk/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:24,759 INFO tr/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:25,169 INFO pt-br/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:25,541 INFO pl/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:25,820 INFO ko/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:26,652 INFO ja/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:26,920 INFO it/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:27,175 INFO id/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:27,500 INFO fr/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:28,223 INFO es/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:28,313 INFO en/3.12: Nothing changed, no rebuild needed.
2023-10-27 09:49:31,085 INFO zh-tw/3.13: Should rebuild: new translations (from f24fd11929f41176367f42559c62b808e7468b2d to eaccd60ee755daee77d4fe24707c1a2ec6059bfb)
2023-10-27 11:08:41,249 INFO zh-cn/3.13: Should rebuild: Doc/ has changed (from a254120f2f1dd99fa64f12594d1ed19c67df7d64 to 74f0772892c85b6e7bdfa0f44a5ff89002b0734d)
2023-10-27 12:31:52,133 INFO uk/3.13: Should rebuild: Doc/ has changed (from 3f84a19e6291db682fc9a570e7612e80e2ffbbb5 to 74f0772892c85b6e7bdfa0f44a5ff89002b0734d)
2023-10-27 12:35:32,533 INFO tr/3.13: Should rebuild: Doc/ has changed (from 3f84a19e6291db682fc9a570e7612e80e2ffbbb5 to 74f0772892c85b6e7bdfa0f44a5ff89002b0734d)
2023-10-27 13:08:20,924 INFO pt-br/3.13: Should rebuild: Doc/ has changed (from 3f84a19e6291db682fc9a570e7612e80e2ffbbb5 to 74f0772892c85b6e7bdfa0f44a5ff89002b0734d)

The last https://docs.python.org/3/ build was at Dec 07, 2023 (12:24 UTC).

The 3.12.1 release was at something like Dec 08, 2023 (00:45 UTC).

As there's no public logs yet (#174), I'm curious why there's been no build yet from the hourly cron. Is the queue full, or maybe something else up?

This relates to https://discuss.python.org/t/python-3-12-1-now-available/40603/2?u=hugovk: a request for release announcements to include the changelog, but the changelog at https://docs.python.org/3/whatsnew/changelog.html still shows "Next" and not "3.12.1".

It turns out we have inadvertently been running the full latexmk process twice for every build, since around 2010. Luckily, this is fixable.

The LaTex build in Sphinx generates a makefile which we use to run latexmk and generate the actual PDFs from the .tex sources that Sphinx creates. In CPython's Doc/Makefile, we call that makefile in a submake: (cd build/latex; make clean && make all-pdf && make FMT=pdf zip bz2).

Considering the generated Makefile at Doc/build/latex/Makefile, the all-pdf target depends on $(ALLPDF), a list of every desired PDF file. The zip and bz2 targets also depend on $(ALLPDF). All three of all-pdf, zip, and bz2 are .PHONY targets, which are evaluated every time make runs. Normally, this wouldn't present an issue, as the zip and bz2 targets depend on $(ALLPDF) rather than all-pdf, so make would know not to rebuild the PDF files. The issue becomes clear with the %.pdf target. By depending on the .PHONY target FORCE_MAKE, PDF files are forcibly regenerated on both invocations of make, bypassing the inbuilt artefact caching.

Resolving this is straightforwards, and I have a branch prepared to open a PR to CPython. EDIT: I have opened the PR at python/cpython#123113.

Sample timings (8 core CPU, via WSL):

Variant	Command	time (real)
Parallel with `-xelatex`	`make -j LATEXMKOPTS="-xelatex" all-pdf && make FMT=pdf zip bz2`	13m55s
As above, fixed makefile targets	`make -j LATEXMKOPTS="-xelatex" all-pdf && make FMT=pdf zip bz2`	5m54s
As above, without `-xelatex`	`make -j all-pdf && make FMT=pdf zip bz2`	5m55s
As above, max 12 jobs	`make -j12 all-pdf && make FMT=pdf zip bz2`	6m4s

I am proposing to use the final option, as whilst not the absolute fastest, it helps to mitigate scheduling problems, and the docs server only has 4 CPU cores, per Hugo's comment. It seems that -xelatex doesn't make a massive difference here.

A

Good catch! The blame is on me at sphinx-doc/sphinx@409605d, but to my defence former Makefile did 5 (pdf)latex builds each time. Actually re-reading your post I am wondering if latexmk really triggers again xelatex. It should say something like this (this is an example on a dummy project)

$ make -C _build/latex all-pdf
make : on entre dans le répertoire « /pathto/sphinxtests/12778_box-shadow/_build/latex »
latexmk -pdf -dvi- -ps-  'foo.tex'
Rc files read:
  latexmkrc
Latexmk: This is Latexmk, John Collins, 7 Apr. 2024. Version 4.85.
Latexmk: Nothing to do for 'foo.tex'.
Latexmk: All targets (foo.pdf) are up-to-date

make : on quitte le répertoire « /pathto/sphinxtests/12778_box-shadow/_build/latex »

I am proposing to use the final option, as whilst not the absolute fastest, it helps to mitigate scheduling problems, and the docs server only has 4 CPU cores, per Hugo's comment

I think one has to make sure none of the 4 or 5 biggest files end up being handled by same core which may require a more complex layer to first list files as per decreasing filesizes of the .tex and feed them in that order to make as pdf targets.

It seems that -xelatex doesn't make a massive difference here.

~~Yes Sphinx docs is too optimistic about this. It makes a difference when build documents does a ton of graphics inclusions.~~ Sphinx docs does say it makes a difference in case of tons of graphics inclusions.

@AA-Turner

With @AA-Turner's latexmk improvements (#169 (comment)) we're saving about a third of the time!

Here's a difference in the build times (not publish and so on) for a full set of 3.14 builds:

Before		After		Difference
Lang/version	Build (minutes)	Lang/version	Build (minutes)	Time saved (minutes)	Times as fast
zh-tw/3.14	119.4	zh-tw/3.14	96.7	22.8	0.81
zh-cn/3.14	108.7	zh-cn/3.14	82.1	26.7	1.32
uk/3.14	4.7	uk/3.14	3.7	1.0	1.27
tr/3.14	145.3	tr/3.14	94.8	50.5	1.53
pt-br/3.14	54.9	pt-br/3.14	37.1	17.7	1.48
pl/3.14	44.1	pl/3.14	29.4	14.7	1.50
ko/3.14	72.3	ko/3.14	44.0	28.2	1.64
ja/3.14	125.2	ja/3.14	70.0	55.2	1.79
it/3.14	45.4	it/3.14	30.1	15.2	1.51
id/3.14	59.3	id/3.14	37.4	21.8	1.58
es/3.14	162.5	es/3.14	102.7	59.8	1.58
en/3.14	45.9	en/3.14	27.7	18.2	1.66

Total minutes:	987.7		655.7	332.0	1.51
Total hours:	16.5		10.9	5.5	1.51

PS Here's the separate before and after times, and the script I used to get the times from the server build times.

before

Start	Language/version	Build
2024-08-18 21:33	zh-tw/3.14	1h 59m
2024-08-18 23:33	zh-cn/3.14	1h 48m
2024-08-19 01:24	uk/3.14	4m
2024-08-19 01:30	tr/3.14	2h 25m
2024-08-19 03:57	pt-br/3.14	54m
2024-08-19 04:53	pl/3.14	44m
2024-08-19 05:38	ko/3.14	1h 12m
2024-08-19 06:51	ja/3.14	2h 5m
2024-08-19 08:58	it/3.14	45m
2024-08-19 09:45	id/3.14	59m
2024-08-19 11:23	es/3.14	2h 42m
2024-08-19 14:07	en/3.14	45m

after

Start	Language/version	Build
2024-08-24 16:07	zh-tw/3.14	1h 36m
2024-08-24 17:44	zh-cn/3.14	1h 22m
2024-08-24 19:08	uk/3.14	3m
2024-08-24 19:13	tr/3.14	1h 34m
2024-08-24 20:49	pt-br/3.14	37m
2024-08-24 21:27	pl/3.14	29m
2024-08-24 21:57	ko/3.14	44m
2024-08-24 22:42	ja/3.14	1h 10m
2024-08-24 23:54	it/3.14	30m
2024-08-25 00:25	id/3.14	37m
2024-08-25 01:28	es/3.14	1h 42m
2024-08-25 03:12	en/3.14	27m

calc-times.py

"""
Example log:
2024-08-14 09:07:13,383 INFO zh-tw/3.12: Build start.
2024-08-14 09:07:13,384 INFO zh-tw/3.12: Running make autobuild-stable
2024-08-14 09:07:13,384 DEBUG zh-tw/3.12: Run: "sed -i 's/ *-A switchers=1//' /srv/docsbuild/cpython/Doc/Makefile"
2024-08-14 09:07:13,392 DEBUG zh-tw/3.12: Run: "make -C /srv/docsbuild/cpython/Doc PYTHON=/srv/docsbuild/venv-3.12/bin/python SPHINXBUILD=/srv/docsbuild/venv-3.12/bin/sphinx-build BLURB=/srv/docsbuild/venv-3.12/bin/blurb VENVDIR=/srv/docsbuild/venv-3.12 'SPHINXOPTS=-D latex_engine=xelatex -D latex_elements.inputenc= -D latex_elements.fontenc=\\\\usepackage{xeCJK} -q -D locale_dirs=/srv/docsbuild/3.12/locale -D language=zh_TW -D gettext_compact=0' SPHINXERRORHANDLING= autobuild-stable"
2024-08-14 10:07:01,951 INFO: Another builder is running... dying...
2024-08-14 10:46:22,454 DEBUG zh-tw/3.12: Run: 'mkdir -p /var/log/docsbuild'
2024-08-14 10:46:22,462 DEBUG zh-tw/3.12: Run: 'chgrp -R docs /var/log/docsbuild'
2024-08-14 10:46:23,852 INFO zh-tw/3.12: Build done.
"""

import argparse
import datetime as dt
import glob
from functools import cache

from prettytable import MARKDOWN, PrettyTable


@cache
def format_seconds(seconds: float) -> str:
    hours, minutes = divmod(seconds, 3600)
    minutes, _ = divmod(minutes, 60)
    hours, minutes = int(hours), int(minutes)

    match (hours, minutes):
        case 0, m:
            return f"{m}m"
        case h, m:
            return f"{h}h {m}m"


def get_lines(logfiles: list[str]) -> list[str]:
    lines = []
    for logfile in logfiles:
        if logfile.endswith(".gz"):
            continue

        with open(logfile) as f:
            lines.extend(f.readlines())

    return lines


def calc_time(lines: list[str]) -> None:
    start = end = language_version = start_timestamp = None

    table = PrettyTable()
    table.set_style(MARKDOWN)
    table.field_names = ["Start", "Language/version", "Build"]
    table.align["Build"] = "r"

    for line in lines:
        line = line.strip()
        if line.endswith("Build start."):
            timestamp = line[:23].replace(",", ".")
            language_version = line.split(" ")[3].removesuffix(":")
            start = dt.datetime.strptime(timestamp, "%Y-%m-%d %H:%M:%S.%f")
            start_timestamp = line[:16]

        if start and line.endswith("Build done."):
            timestamp = line[:23].replace(",", ".")
            language_version = line.split(" ")[3].removesuffix(":")
            end = dt.datetime.strptime(timestamp, "%Y-%m-%d %H:%M:%S.%f")

        if start and end:
            table.add_row(
                [
                    start_timestamp,
                    language_version,
                    # format_seconds((end - start).total_seconds()),
                    (end - start).total_seconds()/60,
                ]
            )
            start = end = None

    print(table)


def main():
    parser = argparse.ArgumentParser()
    parser.add_argument(
        "logfiles", help="log file to read", nargs="?", default="docsbuild.log*"
    )
    args = parser.parse_args()
    logfiles = glob.glob(args.logfiles)
    lines = sorted(get_lines(logfiles))
    calc_time(lines)


if __name__ == "__main__":
    main()

If you can build in an environment with a LaTeX distribution based upon TeXLive 2019 you will probably observe 30% or more additional gain. See this comment. I can not guarantee it completely because the comment compared builds on TL2019 and TL2024 and you use a Debian TL2023, so the gain might not be as much (I currently can not test on a TL2023). The PDFs will be exactly identical.

edit: I mean will look and print identical. Perhaps things are different regarding copy-paste from PDF and some other matters.

(I can not quantify at this time if the change from TL2023 to TL2024 induced the major part in slow-down of LaTeX kernel, or if it occurred earlier).

Another 30% or more would be very welcome! But I'm not too sure if we should downgrade to an unsupported version? (Or how to do it.)

A docker image is available for all TeXLive versions since 2014. The problem is that it contains the full thing which is much much more than what is strictly needed for Sphinx make latexpdf even leaving aside all sources and all documentation. Unfortunately I have personally no experience with this (having multiple TeXLive's on my computer already there), and to start with I have no idea if you can use such a Docker image and if its large size is an impediment (and I have other tasks now).

There is a sphinx-latexpdf Docker image used for our CI, if I knew the recipe I could modify it to use TeXLive2019. And in the process try to use a much smaller part of full TeXLive hence construct a much smaller Docker image. But this is time-consuming task for which I don't have the immediate qualifications.

Update, we've cut the build times by around another third, by cutting about 15h per full build loop through dropping the letter PDF build (and keeping A4 PDF):

Drop one of the two PDF sizes docs-community#128 (comment)

And by about an extra half an hour by re-using an HTTPS connection for purging CDN URLs:

Speed up CDN purges by re-using a pool manager #184 (comment)

It seems we're currently running around 10h 40m for each version -- Python 3.13 hasn't done a full rebuild in a while as the last commit was a fortnight ago (save around a dozen in the last half-hour!). This would be roughly 32 hours for a full rebuild of 3.12--3.14.

Timings:

Start	Version	Language	Build	Reason
2024-09-20 11:07 GMT	3.14	zh-tw	1h 45m	docs
2024-09-20 12:53 GMT	3.14	zh-cn	1h 38m	docs
2024-09-20 14:31 GMT	3.14	uk	4m	docs
2024-09-20 14:35 GMT	3.14	tr	1h 2m	docs
2024-09-20 15:38 GMT	3.14	pt-br	31m	docs
2024-09-20 16:10 GMT	3.14	pl	24m	docs
2024-09-20 16:35 GMT	3.14	ko	35m	docs
2024-09-20 17:10 GMT	3.14	ja	55m	docs
2024-09-20 18:06 GMT	3.14	it	24m	docs
2024-09-20 18:31 GMT	3.14	id	32m	docs
2024-09-20 19:04 GMT	3.14	fr	24m	docs
2024-09-20 19:29 GMT	3.14	es	1h 14m	docs
2024-09-20 20:43 GMT	3.14	en	23m	docs
2024-09-20 21:07 GMT	3.13	zh-cn	1h 48m	translation
2024-09-20 23:24 GMT	3.12	zh-tw	1h 37m	docs
2024-09-21 01:02 GMT	3.12	zh-cn	1h 21m	translation
2024-09-21 02:24 GMT	3.12	uk	3m	docs
2024-09-21 02:28 GMT	3.12	tr	1h 2m	docs
2024-09-21 03:31 GMT	3.12	pt-br	27m	translation
2024-09-21 04:00 GMT	3.12	pl	23m	translation
2024-09-21 04:23 GMT	3.12	ko	30m	docs
2024-09-21 04:53 GMT	3.12	ja	44m	translation
2024-09-21 05:38 GMT	3.12	it	21m	docs
2024-09-21 06:01 GMT	3.12	id	33m	docs
2024-09-21 06:35 GMT	3.12	fr	22m	docs
2024-09-21 06:58 GMT	3.12	es	1h 6m	docs
2024-09-21 08:05 GMT	3.12	en	20m	docs
2024-09-21 08:30 GMT	--FULL-	-BUILD--	21h 23m 31s	-----------
2024-09-21 09:07 GMT	3.14	zh-cn	1h 29m	translation
2024-09-21 10:37 GMT	3.14	uk	4m	translation
2024-09-21 10:41 GMT	3.14	pt-br	29m	translation
2024-09-21 11:11 GMT	3.14	ja	52m	translation
2024-09-21 12:04 GMT	3.13	zh-cn	1h 37m	translation
2024-09-21 13:42 GMT	3.13	uk	4m	translation
2024-09-21 13:46 GMT	3.13	pt-br	43m	translation
2024-09-21 14:30 GMT	3.13	ja	1h 22m	translation
2024-09-21 16:24 GMT	3.12	uk	3m	translation
2024-09-21 16:34 GMT	--FULL-	-BUILD--	7h 27m 6s	-----------
2024-09-21 17:07 GMT	3.14	zh-cn	1h 29m	translation
2024-09-21 18:37 GMT	3.13	zh-cn	1h 37m	translation
2024-09-21 20:48 GMT	--FULL-	-BUILD--	3h 41m 24s	-----------
2024-09-21 21:41 GMT	--FULL-	-BUILD--	34m 43s	-----------
2024-09-21 22:39 GMT	--FULL-	-BUILD--	32m 36s	-----------
2024-09-21 23:39 GMT	--FULL-	-BUILD--	32m 17s	-----------
2024-09-22 00:07 GMT	3.14	pt-br	29m	translation
2024-09-22 00:37 GMT	3.14	ja	53m	translation
2024-09-22 01:31 GMT	3.13	pt-br	43m	translation
2024-09-22 03:41 GMT	3.12	ja	42m	translation
2024-09-22 04:29 GMT	--FULL-	-BUILD--	4h 22m 7s	-----------
2024-09-22 05:07 GMT	3.14	zh-cn	1h 25m	translation
2024-09-22 06:33 GMT	3.14	uk	4m	translation
2024-09-22 06:38 GMT	3.13	zh-cn	1h 36m	translation
2024-09-22 08:15 GMT	3.13	uk	4m	translation
2024-09-22 08:19 GMT	3.13	ja	1h 21m	translation
2024-09-22 10:10 GMT	3.12	uk	3m	translation
2024-09-22 10:19 GMT	--FULL-	-BUILD--	5h 12m 32s	-----------
2024-09-22 11:07 GMT	3.14	zh-cn	1h 27m	translation
2024-09-22 12:35 GMT	3.14	pl	22m	translation
2024-09-22 12:58 GMT	3.13	zh-cn	1h 43m	translation
2024-09-22 14:42 GMT	3.13	pl	36m	translation
2024-09-22 15:49 GMT	3.12	zh-cn	1h 20m	translation
2024-09-22 17:15 GMT	--FULL-	-BUILD--	6h 8m 23s	-----------
2024-09-22 18:07 GMT	3.14	zh-cn	1h 30m	translation
2024-09-22 19:38 GMT	3.13	zh-cn	1h 42m	translation
2024-09-22 21:56 GMT	--FULL-	-BUILD--	3h 49m 44s	-----------
2024-09-22 22:43 GMT	--FULL-	-BUILD--	36m 14s	-----------
2024-09-22 23:38 GMT	3.12	zh-tw	1h 37m	translation
2024-09-23 01:16 GMT	3.12	ja	43m	translation
2024-09-23 02:05 GMT	--FULL-	-BUILD--	2h 58m 32s	-----------
2024-09-23 02:07 GMT	3.14	zh-tw	1h 42m	translation
2024-09-23 03:50 GMT	3.14	zh-cn	1h 25m	translation
2024-09-23 05:15 GMT	3.14	pt-br	28m	translation
2024-09-23 05:44 GMT	3.14	ja	59m	translation
2024-09-23 06:44 GMT	3.13	zh-tw	1h 57m	translation
2024-09-23 08:42 GMT	3.13	zh-cn	1h 38m	translation
2024-09-23 10:21 GMT	3.13	uk	4m	translation
2024-09-23 10:26 GMT	3.13	pt-br	45m	translation
2024-09-23 11:11 GMT	3.13	ja	1h 25m	translation
2024-09-23 13:07 GMT	3.12	zh-tw	1h 44m	translation
2024-09-23 14:52 GMT	3.12	zh-cn	1h 26m	docs
2024-09-23 16:19 GMT	3.12	uk	3m	translation
2024-09-23 16:23 GMT	3.12	tr	1h 2m	docs
2024-09-23 17:26 GMT	3.12	pt-br	29m	docs
2024-09-23 17:56 GMT	3.12	pl	In progress...	docs

(reason is 'translation' if an updated translation caused the rebuild rather than updated docs, and 'FULL BUILD' captures the end of a full rebuild loop. The loops that are 'empty' but around 30m long attempt a build of fr/3.13 and fail, see #187)

A

Python 3.13 hasn't done a full rebuild in a while as the last commit was a fortnight ago (save around a dozen in the last half-hour!)

This initially caught me by surprise but is expected; the 3.13 branch is locked for RC2, so there's not been much merged on the branch recently:

There is a sphinx-latexpdf Docker image used for our CI, if I knew the recipe I could modify it to use TeXLive2019.

This is the recipe: https://github.com/csotomon/sphinx-docker/blob/master/latexpdf/Dockerfile

That link is to a fork, though it's unclear -- the up-to-date dockerfile is at https://github.com/sphinx-doc/sphinx-docker-images/blob/master/latexpdf/Dockerfile

I suggest that we close this issue in favour of #209, now that python/docs-community#131 has been implemented. The non-HTML archive builds still take a while, but it's a manageable duration and we now have the luxury of adjusting the frequency of those builds to e.g. once every two days rather than daily.

Thank you to everyone involved for the help in reducing build times, we have made significant strides here in a challenging problem straddling multiple teams, projects, and repos.

A

Here's a summary of the current times, much improved:
python/docs-community#131 (comment)

Yes, let's close and continue in other issues as needed.

Thanks all!

Navigation Menu

Full build with PDF is taking more than 24h #169

25 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Full build with PDF is taking more than 24h #169

Description

Activity

egeakman commented on Oct 5, 2023

egeakman commented on Oct 5, 2023

JulienPalard commented on Oct 5, 2023

egeakman commented on Oct 5, 2023

JulienPalard commented on Oct 5, 2023

picnixz commented on Oct 8, 2023

JulienPalard commented on Oct 11, 2023

m-aciek commented on Oct 11, 2023

picnixz commented on Oct 12, 2023

JulienPalard commented on Oct 12, 2023

picnixz commented on Oct 12, 2023

JulienPalard commented on Oct 12, 2023

JulienPalard commented on Oct 22, 2023

JulienPalard commented on Oct 27, 2023

hugovk commented on Dec 8, 2023

25 remaining items

AA-Turner commented on Aug 17, 2024

jfbu commented on Aug 17, 2024

jfbu commented on Aug 17, 2024

hugovk commented on Aug 25, 2024

jfbu commented on Aug 25, 2024

hugovk commented on Aug 25, 2024

jfbu commented on Aug 25, 2024

hugovk commented on Sep 18, 2024

AA-Turner commented on Sep 23, 2024

hugovk commented on Sep 23, 2024

merwok commented on Oct 1, 2024

AA-Turner commented on Oct 1, 2024

AA-Turner commented on Oct 2, 2024

hugovk commented on Oct 2, 2024

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions