Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
JulienPalard opened this issue Oct 5, 2023 · 54 comments
Closed

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

JulienPalard opened this issue Oct 5, 2023 · 54 comments

Comments

@JulienPalard
Copy link
Member

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).

@egeakman
Copy link
Contributor

egeakman commented Oct 5, 2023

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.

@egeakman
Copy link
Contributor

egeakman commented Oct 5, 2023

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

@JulienPalard
Copy link
Member Author

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.

@egeakman
Copy link
Contributor

egeakman commented Oct 5, 2023

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

@JulienPalard
Copy link
Member Author

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.

@picnixz
Copy link
Member

picnixz commented Oct 8, 2023

@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.

@JulienPalard
Copy link
Member Author

JulienPalard commented Oct 11, 2023

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.

@m-aciek
Copy link
Contributor

m-aciek commented Oct 11, 2023

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.

@picnixz
Copy link
Member

picnixz commented Oct 12, 2023

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.

@JulienPalard
Copy link
Member Author

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).

@picnixz
Copy link
Member

picnixz commented Oct 12, 2023

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).

@JulienPalard
Copy link
Member Author

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...

? 

@JulienPalard
Copy link
Member Author

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

@JulienPalard
Copy link
Member Author

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)

@hugovk
Copy link
Member

hugovk commented Dec 8, 2023

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".

@willingc
Copy link

@hugovk @JulienPalard What are the next steps needed for this?

@JulienPalard
Copy link
Member Author

I see the last build on Last updated on Dec 11, 2023 (04:33 UTC), so the build is running, still slow though.

@hugovk
Copy link
Member

hugovk commented Dec 12, 2023

It now says Last updated on Dec 12, 2023 (08:00 UTC) on https://docs.python.org/3/

If it took 27.5 hours, what language/versions has it been building to delay it?

There have been changes to 3.11-3.13 in the past day, but a week or more for 3.10 and older.

@JulienPalard
Copy link
Member Author

Since we stopped rebuilding when it's not needed, we're maintaining a file with some infos:

see file
["/zh-tw/3.11/"]
cpython_sha = "694631ca14255b749c565042b0d891aaf04d40c0"
translation_sha = "1e356ff418870ee2ae86282e3e11631658d47c68"
last_build = 2023-12-13T20:58:43.394089Z
last_build_duration = 3098.094585299492

["/zh-cn/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "d7821cb1251d4e449112ab0a4fbe23030113f555"
last_build = 2023-12-12T20:52:34.953898Z
last_build_duration = 3103.580232806504

["/uk/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "83cc16b77a8dd606ef93af89edd45d8f4dd4ac7a"
last_build = 2023-12-12T20:56:05.815128Z
last_build_duration = 210.76982203125954

["/tr/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "a0aef1684ec26d77c1cfc253fada24e42ae7170c"
last_build = 2023-12-12T21:25:28.430790Z
last_build_duration = 1762.5443530604243

["/pt-br/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "93b01be79fa6d44a4500583459e7734fa16c7edc"
last_build = 2023-12-12T21:54:16.924618Z
last_build_duration = 1728.4081133455038

["/pl/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "ad3f03c2da957270a4524adfdf47620494cfd20d"
last_build = 2023-12-12T22:20:45.157714Z
last_build_duration = 1588.139028944075

["/ko/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "dada54826f66869e7c0f58193da81c99cd6fc3c6"
last_build = 2023-12-12T22:56:47.261816Z
last_build_duration = 2162.023073770106

["/ja/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "841afcc48089933831e6b5f910b61f042b41f5ce"
last_build = 2023-12-13T00:23:37.409970Z
last_build_duration = 5210.0655683502555

["/it/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "aebe05830ccf79e5a1261f5c31ce50872295144e"
last_build = 2023-12-13T00:48:17.921699Z
last_build_duration = 1480.389074318111

["/id/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "9ba591b54e465b7d75b20f26863f970e463e46e8"
last_build = 2023-12-13T01:19:23.170320Z
last_build_duration = 1865.1707886829972

["/fr/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "9ebdd501aca1c528907db8c40460271e4983722f"
last_build = 2023-12-13T01:46:38.513918Z
last_build_duration = 1635.2293921038508

["/es/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
translation_sha = "169b71e2847a5c679b5e08b213c2581fa0035bb7"
last_build = 2023-12-13T02:16:37.559038Z
last_build_duration = 1798.9707588106394

["/en/3.11/"]
cpython_sha = "f78f6b6e89b9816d0a8de4bc7eaa01edb93e4b80"
last_build = 2023-12-13T02:40:36.184253Z
last_build_duration = 1438.521405339241

["/zh-tw/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "3d1b20dc3008195f1cc644ad582948199ccd6e58"
last_build = 2023-12-13T03:30:18.147043Z
last_build_duration = 2981.8536808416247

["/zh-cn/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "75ad56739df6d3e9bff7307c2a289dc5f7c88b01"
last_build = 2023-12-13T04:18:34.099284Z
last_build_duration = 2895.865228138864

["/uk/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "e3beb58e3e443dda3741d38b4a041aa157ae70cb"
last_build = 2023-12-13T04:22:04.852000Z
last_build_duration = 210.6848026663065

["/tr/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "1e1cabc2c897decad6f3113d9172a14b2faa7c3d"
last_build = 2023-12-13T04:50:26.476017Z
last_build_duration = 1701.536269709468

["/pt-br/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "ea139bb4814d28057f7b62d767ff2fc33ca2393c"
last_build = 2023-12-13T05:18:19.731717Z
last_build_duration = 1673.1806314513087

["/pl/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "fb5d3ef124b497a0abe87227d8e7fd7c5f2ef7ea"
last_build = 2023-12-13T05:43:32.126013Z
last_build_duration = 1512.2927004247904

["/ko/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "dada54826f66869e7c0f58193da81c99cd6fc3c6"
last_build = 2023-12-13T06:18:38.229082Z
last_build_duration = 2106.0200723856688

["/ja/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "97ff29fa511d414981898658199e4d9e7afeb45d"
last_build = 2023-12-13T07:42:33.870205Z
last_build_duration = 5035.5601375103

["/it/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "aebe05830ccf79e5a1261f5c31ce50872295144e"
last_build = 2023-12-13T08:08:05.896664Z
last_build_duration = 1531.9528702422976

["/id/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "9ba591b54e465b7d75b20f26863f970e463e46e8"
last_build = 2023-12-13T08:41:17.613854Z
last_build_duration = 1991.6177273616195

["/fr/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "9ebdd501aca1c528907db8c40460271e4983722f"
last_build = 2023-12-13T09:08:47.270563Z
last_build_duration = 1649.590953759849

["/es/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
translation_sha = "23991c3d509c8cb223f1a8dd262988d844e42f34"
last_build = 2023-12-13T09:39:05.043432Z
last_build_duration = 1817.7011435106397

["/en/3.12/"]
cpython_sha = "b884d21f10f228bef11980e076af53343e686463"
last_build = 2023-12-13T10:03:40.042323Z
last_build_duration = 1474.9010257422924

["/zh-tw/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "644b84e9dc6fb79c79e3ca1c5015fd21da9c6f62"
last_build = 2023-12-13T11:30:50.976827Z
last_build_duration = 5230.8338821306825

["/zh-cn/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "75ad56739df6d3e9bff7307c2a289dc5f7c88b01"
last_build = 2023-12-13T13:02:59.424127Z
last_build_duration = 5528.383116334677

["/uk/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "e3beb58e3e443dda3741d38b4a041aa157ae70cb"
last_build = 2023-12-13T13:06:51.197718Z
last_build_duration = 231.70681616663933

["/tr/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "1e1cabc2c897decad6f3113d9172a14b2faa7c3d"
last_build = 2023-12-13T13:40:24.260783Z
last_build_duration = 2012.9675337076187

["/pt-br/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "ea139bb4814d28057f7b62d767ff2fc33ca2393c"
last_build = 2023-12-13T14:13:29.505903Z
last_build_duration = 1985.1673073396087

["/pl/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "fb5d3ef124b497a0abe87227d8e7fd7c5f2ef7ea"
last_build = 2023-12-13T14:44:47.217278Z
last_build_duration = 1877.6119738593698

["/ko/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "dada54826f66869e7c0f58193da81c99cd6fc3c6"
last_build = 2023-12-13T15:24:54.988656Z
last_build_duration = 2407.6938998550177

["/ja/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "97ff29fa511d414981898658199e4d9e7afeb45d"
last_build = 2023-12-13T17:02:30.116978Z
last_build_duration = 5855.0243775472045

["/it/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "aebe05830ccf79e5a1261f5c31ce50872295144e"
last_build = 2023-12-13T17:34:32.321583Z
last_build_duration = 1922.1185678616166

["/id/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "9ba591b54e465b7d75b20f26863f970e463e46e8"
last_build = 2023-12-13T18:17:12.805072Z
last_build_duration = 2560.38579890877

["/fr/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "9ebdd501aca1c528907db8c40460271e4983722f"
last_build = 2023-12-13T18:50:52.892841Z
last_build_duration = 2019.9838555455208

["/es/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
translation_sha = "23991c3d509c8cb223f1a8dd262988d844e42f34"
last_build = 2023-12-13T19:28:22.535989Z
last_build_duration = 2249.569005407393

["/en/3.13/"]
cpython_sha = "956023826a393b5704d3414dcd01f1bcbeaeda15"
last_build = 2023-12-13T19:59:47.479534Z
last_build_duration = 1884.880883552134

["/zh-tw/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "33d6fb4102d6565764a3c364a07de51d112b44d2"
last_build = 2023-11-14T09:03:40.183755Z
last_build_duration = 3398.2279169410467

["/zh-cn/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "fb1a27f77113140559d5e595f2d80d9598c7231f"
last_build = 2023-11-14T09:56:25.654707Z
last_build_duration = 3165.389776684344

["/uk/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "a91fd1b5d1dcad4a679f29da9dc9ddcba87545ba"
last_build = 2023-11-14T09:59:58.765924Z
last_build_duration = 212.99671158194542

["/tr/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "7c7c3b0349a1238a8c72da8f0f5de7cf68527833"
last_build = 2023-11-14T10:31:35.691285Z
last_build_duration = 1896.8465352505445

["/pt-br/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "948372e472c6dc03a2bc8c82f7d8fbe3309b272b"
last_build = 2023-11-14T11:01:05.771282Z
last_build_duration = 1770.0178842619061

["/pl/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "b823635d9d1a216dccbbadef44ab282987f31283"
last_build = 2023-11-14T11:27:19.901667Z
last_build_duration = 1574.0320699512959

["/ko/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "dada54826f66869e7c0f58193da81c99cd6fc3c6"
last_build = 2023-11-14T12:05:27.032940Z
last_build_duration = 2287.0581825375557

["/ja/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "adde31e5584af8266413d1997324c44c5a0bc865"
last_build = 2023-11-14T13:39:15.475070Z
last_build_duration = 5628.3420650959015

["/it/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "aebe05830ccf79e5a1261f5c31ce50872295144e"
last_build = 2023-11-14T14:06:35.699216Z
last_build_duration = 1640.0956600159407

["/id/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "9ba591b54e465b7d75b20f26863f970e463e46e8"
last_build = 2023-11-14T14:39:29.752166Z
last_build_duration = 1973.9433364644647

["/fr/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "fba25673317c237be4e95709a52203c2564375d2"
last_build = 2023-11-14T15:08:32.529183Z
last_build_duration = 1742.671448096633

["/es/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
translation_sha = "e37b282476c5f9261c0ca2ac7e8db6e6f6f9bcd7"
last_build = 2023-11-14T15:47:58.007060Z
last_build_duration = 2365.3818720132113

["/en/3.10/"]
cpython_sha = "6c2f34fa77f884bd79801a9ab8a117cab7d9c7ed"
last_build = 2023-11-14T16:12:52.351156Z
last_build_duration = 1494.2587717548013

it's not that readable but may help a bit.

I can paste some logs here:

view file
mdk@docs:~$ zgrep 'Build start' /var/log/docsbuild/docsbuild.log.6.gz 
2023-12-07 01:03:31,783 INFO it/3.11: Build start.
2023-12-07 01:34:48,312 INFO id/3.11: Build start.
2023-12-07 02:13:16,175 INFO fr/3.11: Build start.
2023-12-07 02:47:08,767 INFO es/3.11: Build start.
2023-12-07 03:24:20,181 INFO en/3.11: Build start.
2023-12-07 03:53:32,721 INFO zh-tw/3.12: Build start.
2023-12-07 04:54:28,702 INFO zh-cn/3.12: Build start.
2023-12-07 05:51:22,955 INFO uk/3.12: Build start.
2023-12-07 05:55:15,983 INFO tr/3.12: Build start.
2023-12-07 06:29:04,896 INFO pt-br/3.12: Build start.
2023-12-07 07:03:29,075 INFO pl/3.12: Build start.
2023-12-07 07:33:25,766 INFO ko/3.12: Build start.
2023-12-07 08:16:09,363 INFO ja/3.12: Build start.
2023-12-07 09:59:31,894 INFO it/3.12: Build start.
2023-12-07 10:29:39,325 INFO id/3.12: Build start.
2023-12-07 11:10:44,153 INFO fr/3.12: Build start.
2023-12-07 11:45:54,247 INFO es/3.12: Build start.
2023-12-07 12:24:23,271 INFO en/3.12: Build start.  <-- the build you've seen in prod while writing your message
2023-12-07 12:55:57,594 INFO zh-tw/3.13: Build start.
2023-12-07 14:58:05,206 INFO zh-cn/3.13: Build start.
2023-12-07 16:59:55,851 INFO uk/3.13: Build start.
2023-12-07 17:06:09,502 INFO tr/3.13: Build start.
2023-12-07 17:53:58,847 INFO pt-br/3.13: Build start.
2023-12-07 18:40:23,044 INFO pl/3.13: Build start.
2023-12-07 19:22:33,254 INFO ko/3.13: Build start.
2023-12-07 20:17:45,832 INFO ja/3.13: Build start.
2023-12-07 22:24:23,323 INFO it/3.13: Build start.
2023-12-07 23:03:59,538 INFO id/3.13: Build start.
2023-12-07 23:50:30,074 INFO fr/3.13: Build start.
mdk@docs:~$ zgrep 'Build start' /var/log/docsbuild/docsbuild.log.5.gz 
2023-12-08 00:29:10,617 INFO es/3.13: Build start.
                           <-- 3.12.1 release
2023-12-08 01:10:12,533 INFO en/3.13: Build start.
2023-12-08 02:07:14,771 INFO zh-tw/3.11: Build start.
2023-12-08 03:02:35,382 INFO zh-cn/3.11: Build start.
2023-12-08 03:55:25,481 INFO uk/3.11: Build start.
2023-12-08 03:58:58,984 INFO tr/3.11: Build start.
2023-12-08 04:30:39,399 INFO pt-br/3.11: Build start.
2023-12-08 05:02:31,596 INFO pl/3.11: Build start.
2023-12-08 05:31:15,058 INFO ko/3.11: Build start.
2023-12-08 06:12:14,383 INFO ja/3.11: Build start.
2023-12-08 07:51:32,897 INFO it/3.11: Build start.
2023-12-08 08:19:59,311 INFO id/3.11: Build start.
                           <-- your message (more or less 1h)
2023-12-08 08:55:57,314 INFO fr/3.11: Build start.
2023-12-08 09:26:26,468 INFO es/3.11: Build start.
2023-12-08 10:01:36,727 INFO en/3.11: Build start.
2023-12-08 10:29:12,557 INFO zh-tw/3.12: Build start.
2023-12-08 11:28:08,345 INFO zh-cn/3.12: Build start.
2023-12-08 12:28:27,897 INFO uk/3.12: Build start.
2023-12-08 12:33:01,923 INFO tr/3.12: Build start.
2023-12-08 13:09:30,960 INFO pt-br/3.12: Build start.
2023-12-08 13:45:39,082 INFO pl/3.12: Build start.
2023-12-08 14:17:58,792 INFO ko/3.12: Build start.
2023-12-08 15:02:13,565 INFO ja/3.12: Build start.
2023-12-08 16:49:28,995 INFO it/3.12: Build start.
2023-12-08 17:24:15,640 INFO id/3.12: Build start.
2023-12-08 18:03:34,328 INFO fr/3.12: Build start.
2023-12-08 18:35:41,454 INFO es/3.12: Build start.
2023-12-08 19:11:52,848 INFO en/3.12: Build start.  <--
2023-12-08 19:41:12,356 INFO zh-tw/3.13: Build start.
2023-12-08 21:28:18,628 INFO zh-cn/3.13: Build start.
2023-12-08 23:08:18,807 INFO uk/3.13: Build start.
2023-12-08 23:12:37,137 INFO tr/3.13: Build start.
2023-12-08 23:48:46,069 INFO pt-br/3.13: Build start.
mdk@docs:~$ zgrep 'Build start' /var/log/docsbuild/docsbuild.log.4.gz 
2023-12-09 00:25:10,138 INFO pl/3.13: Build start.
2023-12-09 00:57:45,725 INFO ko/3.13: Build start.
2023-12-09 01:40:28,952 INFO ja/3.13: Build start.
2023-12-09 03:21:11,244 INFO it/3.13: Build start.
2023-12-09 03:53:36,108 INFO id/3.13: Build start.
2023-12-09 04:35:39,054 INFO fr/3.13: Build start.
2023-12-09 05:08:42,237 INFO es/3.13: Build start.
2023-12-09 05:44:38,758 INFO en/3.13: Build start.
2023-12-09 07:07:18,041 INFO zh-tw/3.11: Build start.
2023-12-09 07:58:36,484 INFO zh-cn/3.11: Build start.
2023-12-09 08:50:50,170 INFO uk/3.11: Build start.
2023-12-09 08:54:18,539 INFO tr/3.11: Build start.
2023-12-09 09:25:13,308 INFO pt-br/3.11: Build start.
2023-12-09 09:55:38,752 INFO pl/3.11: Build start.
2023-12-09 10:24:47,533 INFO ko/3.11: Build start.
2023-12-09 11:05:06,125 INFO ja/3.11: Build start.
2023-12-09 12:47:05,609 INFO it/3.11: Build start.
2023-12-09 13:17:31,303 INFO id/3.11: Build start.
2023-12-09 13:55:56,164 INFO fr/3.11: Build start.
2023-12-09 14:30:28,217 INFO es/3.11: Build start.
2023-12-09 15:10:10,126 INFO en/3.11: Build start.
2023-12-09 15:40:26,584 INFO zh-tw/3.12: Build start.
2023-12-09 16:42:34,264 INFO zh-cn/3.12: Build start.
2023-12-09 17:43:02,356 INFO uk/3.12: Build start.
2023-12-09 17:47:08,059 INFO tr/3.12: Build start.
2023-12-09 18:21:25,707 INFO pt-br/3.12: Build start.
2023-12-09 18:55:27,545 INFO pl/3.12: Build start.
2023-12-09 19:26:25,268 INFO ko/3.12: Build start.
2023-12-09 20:08:18,771 INFO ja/3.12: Build start.
2023-12-09 21:51:05,595 INFO it/3.12: Build start.
2023-12-09 22:23:04,710 INFO id/3.12: Build start.
2023-12-09 23:03:02,551 INFO fr/3.12: Build start.
2023-12-09 23:36:46,483 INFO es/3.12: Build start.
mdk@docs:~$ zgrep 'Build start' /var/log/docsbuild/docsbuild.log.3.gz 
2023-12-10 00:12:31,758 INFO en/3.12: Build start.  <--
2023-12-10 00:38:36,561 INFO zh-tw/3.13: Build start.
2023-12-10 02:11:45,282 INFO zh-cn/3.13: Build start.
2023-12-10 03:40:09,197 INFO uk/3.13: Build start.
2023-12-10 03:43:59,909 INFO tr/3.13: Build start.
2023-12-10 04:16:53,655 INFO pt-br/3.13: Build start.
2023-12-10 04:50:19,080 INFO pl/3.13: Build start.
2023-12-10 05:21:18,370 INFO ko/3.13: Build start.
2023-12-10 05:59:52,249 INFO ja/3.13: Build start.
2023-12-10 07:39:20,008 INFO it/3.13: Build start.
2023-12-10 08:12:51,583 INFO id/3.13: Build start.
2023-12-10 08:56:53,066 INFO fr/3.13: Build start.
2023-12-10 09:32:21,252 INFO es/3.13: Build start.
2023-12-10 10:10:41,943 INFO en/3.13: Build start.
2023-12-10 11:07:17,607 INFO zh-tw/3.11: Build start.
2023-12-10 12:01:43,511 INFO zh-cn/3.11: Build start.
2023-12-10 12:55:46,836 INFO uk/3.11: Build start.
2023-12-10 12:59:14,477 INFO tr/3.11: Build start.
2023-12-10 13:31:47,797 INFO pt-br/3.11: Build start.
2023-12-10 14:04:52,957 INFO pl/3.11: Build start.
2023-12-10 14:35:04,605 INFO ko/3.11: Build start.
2023-12-10 15:18:22,877 INFO ja/3.11: Build start.
2023-12-10 17:06:49,408 INFO it/3.11: Build start.
2023-12-10 17:40:07,017 INFO id/3.11: Build start.
2023-12-10 18:21:59,182 INFO fr/3.11: Build start.
2023-12-10 18:57:50,425 INFO es/3.11: Build start.
2023-12-10 19:38:27,999 INFO en/3.11: Build start.
2023-12-10 20:09:49,259 INFO zh-tw/3.12: Build start.
2023-12-10 21:13:16,417 INFO zh-cn/3.12: Build start.
2023-12-10 22:14:28,313 INFO uk/3.12: Build start.
2023-12-10 22:18:52,271 INFO tr/3.12: Build start.
2023-12-10 22:52:49,215 INFO pt-br/3.12: Build start.
2023-12-10 23:26:13,913 INFO pl/3.12: Build start.
2023-12-10 23:55:45,872 INFO ko/3.12: Build start.
mdk@docs:~$ zgrep 'Build start' /var/log/docsbuild/docsbuild.log.2.gz 
2023-12-11 00:38:06,339 INFO ja/3.12: Build start.
2023-12-11 02:19:10,223 INFO it/3.12: Build start.
2023-12-11 02:48:39,326 INFO id/3.12: Build start.
2023-12-11 03:25:56,754 INFO fr/3.12: Build start.
2023-12-11 03:57:07,365 INFO es/3.12: Build start.
2023-12-11 04:33:46,003 INFO en/3.12: Build start.  <--
2023-12-11 05:02:28,158 INFO zh-tw/3.13: Build start.
2023-12-11 06:40:57,160 INFO zh-cn/3.13: Build start.
2023-12-11 08:20:40,118 INFO uk/3.13: Build start.
2023-12-11 08:25:12,725 INFO tr/3.13: Build start.
2023-12-11 09:00:10,942 INFO pt-br/3.13: Build start.
2023-12-11 09:31:30,328 INFO pl/3.13: Build start.
2023-12-11 10:00:34,948 INFO ko/3.13: Build start.
2023-12-11 10:38:35,804 INFO ja/3.13: Build start.
2023-12-11 12:15:57,521 INFO it/3.13: Build start.
2023-12-11 12:46:40,636 INFO id/3.13: Build start.
2023-12-11 13:26:24,106 INFO fr/3.13: Build start.
2023-12-11 13:59:58,381 INFO es/3.13: Build start.
2023-12-11 14:39:16,552 INFO en/3.13: Build start.
2023-12-11 16:07:20,776 INFO zh-tw/3.11: Build start.
2023-12-11 17:04:35,431 INFO zh-cn/3.11: Build start.
2023-12-11 18:01:09,964 INFO uk/3.11: Build start.
2023-12-11 18:05:16,722 INFO tr/3.11: Build start.
2023-12-11 18:38:16,662 INFO pt-br/3.11: Build start.
2023-12-11 19:11:47,677 INFO pl/3.11: Build start.
2023-12-11 19:43:07,048 INFO ko/3.11: Build start.
2023-12-11 20:27:02,135 INFO ja/3.11: Build start.
2023-12-11 22:05:54,678 INFO it/3.11: Build start.
2023-12-11 22:33:47,162 INFO id/3.11: Build start.
2023-12-11 23:09:11,730 INFO fr/3.11: Build start.
2023-12-11 23:42:10,783 INFO es/3.11: Build start.

so yes, there's still almost 24h between any builds.

In 14 days we've seen only 45 build being skipped vs 449 rebuilds being needed:

mdk@docs:~$ zgrep 'no rebuild' /var/log/docsbuild/docsbuild.log.*.gz  | wc -l
45
mdk@docs:~$ zgrep 'Should rebuild' /var/log/docsbuild/docsbuild.log.*.gz  | wc -l
449

is is partly due to some translation repos having a cron commiting every day (like transifex pulls) even if there's no new translations in the files.

But the root cause of slow build time is probably more #169 (comment) (latexmk running xelatex in a loop until the result stop changing).

@ewdurbin what "CPU" do we have on the machine? I don't see usefull info on /proc/cpuinfo.

@willingc
Copy link

willingc commented Dec 14, 2023

But the root cause of slow build time is probably more #169 (comment) (latexmk running xelatex in a loop until the result stop changing).

How important are the latex builds?

We may want to look at additional ways of optimizing the latex builds. https://blog.martisak.se/2023/10/01/compiling/

@JulienPalard
Copy link
Member Author

How important are the latex builds?

PDF builds are based on LaTeX builds.

When PDFs are unavailable we have user complaints (typically on docs@).

@willingc
Copy link

willingc commented Dec 14, 2023

Yeah, we definitely need PDFs.

I wonder if it makes sense to try building PDF with an alternate tool, such as pyppeteer which is used by Jupyter book. https://jupyterbook.org/en/stable/advanced/pdf.html#build-a-pdf-from-your-book-html playwright-python.

@willingc
Copy link

Shotscraper could be another approach: https://shot-scraper.datasette.io/en/stable/pdf.html

@methane
Copy link
Member

methane commented Dec 14, 2023

PDF shoud provide table of contents and index.
So ePub is better than html for converting into PDF.

But I don't know good tool to convert ePub to PDF.
Maybe, Calibre?

@m-aciek
Copy link
Contributor

m-aciek commented Dec 14, 2023

What are the versions of latexmk and xetex that are being used on the build server? The latest versions of those packages are 4.81 (2023-11-06) for latexmk and 0.9999.3 (September 2013) for xetex.

@JulienPalard
Copy link
Member Author

mdk@docs:~$ apt-cache policy latexmk
latexmk:
  Installed: 1:4.67-0.1
  Candidate: 1:4.67-0.1
  Version table:
 *** 1:4.67-0.1 500
        500 http://us.archive.ubuntu.com/ubuntu focal/universe amd64 Packages
        100 /var/lib/dpkg/status
mdk@docs:~$ apt-cache policy texlive-xetex
texlive-xetex:
  Installed: 2019.20200218-1
  Candidate: 2019.20200218-1
  Version table:
 *** 2019.20200218-1 500
        500 http://us.archive.ubuntu.com/ubuntu focal/universe amd64 Packages
        100 /var/lib/dpkg/status

@hugovk
Copy link
Member

hugovk commented Aug 16, 2024

What are the versions of latexmk and xetex that are being used on the build server? The latest versions of those packages are 4.81 (2023-11-06) for latexmk and 0.9999.3 (September 2013) for xetex.

The new Ubuntu 24.04 server (python/psf-salt#421) has:

hugovk@docs:~$ apt-cache policy latexmk
latexmk:
  Installed: 1:4.83-1
  Candidate: 1:4.83-1
  Version table:
 *** 1:4.83-1 500
        500 http://mirrors.digitalocean.com/ubuntu noble/universe amd64 Packages
        100 /var/lib/dpkg/status

hugovk@docs:~$ latexmk --version
Latexmk, John Collins, 31 Jan. 2024. Version 4.83
hugovk@docs:~$ apt-cache policy texlive-xetex
texlive-xetex:
  Installed: 2023.20240207-1
  Candidate: 2023.20240207-1
  Version table:
 *** 2023.20240207-1 500
        500 http://mirrors.digitalocean.com/ubuntu noble/universe amd64 Packages
        100 /var/lib/dpkg/status

hugovk@docs:~$ xetex --version
XeTeX 3.141592653-2.6-0.999995 (TeX Live 2023/Debian)
kpathsea version 6.3.5
Copyright 2023 SIL International, Jonathan Kew and Khaled Hosny.
There is NO warranty.  Redistribution of this software is
covered by the terms of both the XeTeX copyright and
the Lesser GNU General Public License.
For more information about these matters, see the file
named COPYING and the XeTeX source.
Primary author of XeTeX: Jonathan Kew.
Compiled with ICU version 74.2; using 74.2
Compiled with zlib version 1.3; using 1.3
Compiled with FreeType2 version 2.13.2; using 2.13.2
Compiled with Graphite2 version 1.3.14; using 1.3.14
Compiled with HarfBuzz version 8.3.0; using 8.3.0
Compiled with libpng version 1.6.43; using 1.6.43
Compiled with pplib version v2.05 less toxic i hope
Compiled with fontconfig version 2.15.0; using 2.15.0

And it has 4 CPUs with 8 GB RAM:

hugovk@docs:~$ cat /proc/cpuinfo  | grep processor
processor	: 0
processor	: 1
processor	: 2
processor	: 3
hugovk@docs:~$ free --human
               total        used        free      shared  buff/cache   available
Mem:           7.8Gi       1.6Gi       4.1Gi       4.3Mi       2.4Gi       6.2Gi
Swap:          1.0Gi          0B       1.0Gi

@hugovk
Copy link
Member

hugovk commented Aug 16, 2024

Here's some observations and a suggestion.

Observations

Whilst checking the fix for #186, for the past couple of days I've been keeping an eye on the server build log and top processes (tail -f /var/log/docsbuild/docsbuild.log and top -i -u docsbuild).

Most of the time is spent on the make -C /srv/docsbuild/cpython/Doc ... commands. Here's logs for a single language/version:

logs
2024-08-16 00:18:06,736 INFO ja/3.12: Running.
2024-08-16 00:18:06,736 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython show-ref -s origin/3.12'
2024-08-16 00:18:06,740 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython reset --hard 41090b7ba06f4b68249b825caf4d06560ed16d9c --'
2024-08-16 00:18:06,778 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython clean -dfqx'
2024-08-16 00:18:07,002 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES fetch'
2024-08-16 00:18:07,738 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES branch -r'
2024-08-16 00:18:07,743 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES show-ref -s origin/3.11'
2024-08-16 00:18:07,746 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES reset --hard 4098cdb388152c9d21ed5a6603aebe756c6fe832 --'
2024-08-16 00:18:08,285 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES clean -dfqx'
2024-08-16 00:18:08,473 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython rev-parse HEAD'
2024-08-16 00:18:08,477 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES rev-parse HEAD'
2024-08-16 00:18:08,480 INFO ja/3.12: Should rebuild: new translations (from 71404d22de96db3df16e11a1d92c39f58cb746f5 to 4098cdb388152c9d21ed5a6603aebe756c6fe832)
2024-08-16 00:18:08,481 DEBUG ja/3.12: Run: '/srv/docsbuild/venv/bin/python -m venv /srv/docsbuild/venv-3.12'
2024-08-16 00:18:11,223 DEBUG ja/3.12: Run: '/srv/docsbuild/venv-3.12/bin/python -m pip install --upgrade python-docs-theme jieba -rrequirements.txt'
2024-08-16 00:18:12,549 DEBUG ja/3.12: Run: '/srv/docsbuild/venv-3.12/bin/python -m pip freeze --all'
2024-08-16 00:18:13,006 INFO ja/3.12: Build start.
2024-08-16 00:18:13,305 INFO ja/3.12: Running make autobuild-stable
2024-08-16 00:18:13,306 DEBUG ja/3.12: Run: "sed -i 's/ *-A switchers=1//' /srv/docsbuild/cpython/Doc/Makefile"
2024-08-16 00:18:13,312 DEBUG ja/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=lualatex -D latex_elements.inputenc= -D latex_elements.fontenc= -D latex_docclass.manual=ltjsbook -D latex_docclass.howto=ltjsarticle -D latex_elements.polyglossia= -D latex_elements.fontpkg= -D latex_elements.preamble=\\\\usepackage[noto-otf]{luatexja-preset}\\\\usepackage{newunicodechar}\\\\newunicodechar{^^^^212a}{K}\\\\makeatletter\\\\titleformat{\\\\subsubsection}{\\\\normalsize\\\\py@HeaderFamily}{\\\\py@TitleColor\\\\thesubsubsection}{0.5em}{\\\\py@TitleColor}\\\\titleformat{\\\\paragraph}{\\\\normalsize\\\\py@HeaderFamily}{\\\\py@TitleColor\\\\theparagraph}{0.5em}{\\\\py@TitleColor}\\\\titleformat{\\\\subparagraph}{\\\\normalsize\\\\py@HeaderFamily}{\\\\py@TitleColor\\\\thesubparagraph}{0.5em}{\\\\py@TitleColor}\\\\makeatother\\\\setlength{\\\\footskip}{16.4pt} -q -D locale_dirs=/srv/docsbuild/3.12/locale -D language=ja -D gettext_compact=0' SPHINXERRORHANDLING= autobuild-stable"
2024-08-16 01:07:02,073 INFO: Another builder is running... dying...
2024-08-16 01:50:41,820 DEBUG ja/3.12: Run: 'mkdir -p /var/log/docsbuild'
2024-08-16 01:50:41,823 DEBUG ja/3.12: Run: 'chgrp -R docs /var/log/docsbuild'
2024-08-16 01:50:42,446 INFO ja/3.12: Build done.
2024-08-16 01:50:42,446 INFO ja/3.12: Publishing start.
2024-08-16 01:50:42,447 DEBUG ja/3.12: Run: 'chgrp -R docs /srv/docs.python.org/ja'
2024-08-16 01:50:42,497 DEBUG ja/3.12: Run: 'chgrp -R docs /srv/docs.python.org/ja/3.12'
2024-08-16 01:50:44,202 INFO ja/3.12: Copying HTML files to /srv/docs.python.org/ja/3.12
2024-08-16 01:50:44,202 DEBUG ja/3.12: Run: 'chown -R :docs /srv/docsbuild/cpython/Doc/build/html'
2024-08-16 01:50:44,214 DEBUG ja/3.12: Run: 'chmod -R o+r /srv/docsbuild/cpython/Doc/build/html'
2024-08-16 01:50:44,223 DEBUG ja/3.12: Run: "find /srv/docsbuild/cpython/Doc/build/html -type d -exec chmod o+x '{}' ';'"
2024-08-16 01:50:44,272 DEBUG ja/3.12: Run: "rsync -a --delete-delay --filter 'P archives/' /srv/docsbuild/cpython/Doc/build/html/ /srv/docs.python.org/ja/3.12"
2024-08-16 01:50:44,688 DEBUG ja/3.12: Copying dist files.
2024-08-16 01:50:44,689 DEBUG ja/3.12: Run: 'chown -R :docs /srv/docsbuild/cpython/Doc/dist'
2024-08-16 01:50:44,691 DEBUG ja/3.12: Run: 'chmod -R o+r /srv/docsbuild/cpython/Doc/dist'
2024-08-16 01:50:44,693 DEBUG ja/3.12: Run: 'mkdir -m o+rx -p /srv/docs.python.org/ja/3.12/archives'
2024-08-16 01:50:44,695 DEBUG ja/3.12: Run: 'chown :docs /srv/docs.python.org/ja/3.12/archives'
2024-08-16 01:50:44,697 DEBUG ja/3.12: Run: 'cp -a /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-text.zip /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-texinfo.zip /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-text.tar.bz2 /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-texinfo.tar.bz2 /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-pdf-a4.tar.bz2 /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-html.zip /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-html.tar.bz2 /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-pdf-letter.zip /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-pdf-a4.zip /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs.epub /srv/docsbuild/cpython/Doc/dist/python-3.12.5-docs-pdf-letter.tar.bz2 /srv/docs.python.org/ja/3.12/archives'
2024-08-16 01:50:44,952 INFO ja/3.12: 862 files changed
2024-08-16 01:50:44,952 DEBUG ja/3.12: Run: 'find -L /srv/docs.python.org -samefile /srv/docs.python.org/ja/3.12'
2024-08-16 01:50:46,185 DEBUG ja/3.12: Purging https://docs.python.org/ja/3/ from CDN
2024-08-16 01:50:46,186 DEBUG ja/3.12: Starting new HTTPS connection (1): docs.python.org:443
2024-08-16 01:50:46,229 DEBUG ja/3.12: https://docs.python.org:443 "PURGE /ja/3/ HTTP/1.1" 200 52

<snip 5172 lines>

2024-08-16 01:52:13,477 DEBUG ja/3.12: Purging https://docs.python.org/ja/3.12/archives/python-3.12.3-docs-pdf-a4.tar.bz2 from CDN
2024-08-16 01:52:13,479 DEBUG ja/3.12: Starting new HTTPS connection (1): docs.python.org:443
2024-08-16 01:52:13,547 DEBUG ja/3.12: https://docs.python.org:443 "PURGE /ja/3.12/archives/python-3.12.3-docs-pdf-a4.tar.bz2 HTTP/1.1" 200 53
2024-08-16 01:52:13,549 INFO ja/3.12: Publishing done
2024-08-16 01:52:13,731 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython rev-parse HEAD'
2024-08-16 01:52:13,734 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES rev-parse HEAD'

When this runs Sphinx, we sometimes get four sphinx-build processes using up to 100% CPU each. This is good, we're making good use of the resources available. (Sometimes there's only 1-2 processes, depending on what part of the build Sphinx is at.)

top - 13:00:14 up 7 days, 14:31,  2 users,  load average: 2.73, 1.59, 1.55
Tasks: 175 total,   7 running, 168 sleeping,   0 stopped,   0 zombie
%Cpu(s): 86.5 us,  1.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.2 si, 11.6 st
MiB Mem :   7941.4 total,   4206.4 free,   1490.0 used,   2581.0 buff/cache
MiB Swap:   1024.0 total,   1024.0 free,      0.0 used.   6451.3 avail Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
 633264 docsbui+  20   0  133336 118608   5376 R  91.1   1.5   0:22.67 sphinx-build
 633365 docsbui+  20   0  130688 115708   5248 R  88.1   1.4   0:07.73 sphinx-build
 633263 docsbui+  20   0  117020 102752   5376 R  86.8   1.3   0:25.98 sphinx-build
 633266 docsbui+  20   0  135080 120984   5632 R  86.8   1.5   0:20.58 sphinx-build

But most of the time it's running a latex command. These only use CPU, but at least generally use 100%:

top - 13:03:45 up 7 days, 14:34,  2 users,  load average: 1.53, 1.99, 1.77
Tasks: 181 total,   2 running, 179 sleeping,   0 stopped,   0 zombie
%Cpu(s): 25.9 us,  0.9 sy,  0.0 ni, 73.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   7941.4 total,   4133.7 free,   1525.6 used,   2618.7 buff/cache
MiB Swap:   1024.0 total,   1024.0 free,      0.0 used.   6415.8 avail Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
 637944 docsbui+  20   0  726692 546544  40048 R 100.0   6.7   0:21.42 xelatex
 637946 docsbui+  20   0   23432  21740   3072 S   4.0   0.3   0:00.82 xdvipdfmx
  81398 docsbui+  20   0   76388  67640  10368 S   0.7   0.8  20:19.58 python

Here's the time between the "Build start"/"Build done" pairs:

table of build times
Start Language/version Build
2024-08-14 00:45 pl/3.14 38m
2024-08-14 01:24 ko/3.14 56m
2024-08-14 02:22 ja/3.14 1h 37m
2024-08-14 04:01 it/3.14 36m
2024-08-14 04:39 id/3.14 45m
2024-08-14 05:55 es/3.14 2h 11m
2024-08-14 08:07 en/3.14 35m
2024-08-14 09:07 zh-tw/3.12 1h 39m
2024-08-14 10:47 zh-cn/3.12 1h 23m
2024-08-14 12:12 uk/3.12 3m
2024-08-14 12:17 pt-br/3.12 44m
2024-08-14 13:03 ko/3.12 56m
2024-08-14 14:01 ja/3.12 1h 32m
2024-08-14 15:35 es/3.12 2h 8m
2024-08-14 17:45 zh-tw/3.13 1h 44m
2024-08-14 19:30 zh-cn/3.13 1h 35m
2024-08-14 21:06 uk/3.13 3m
2024-08-14 21:10 tr/3.13 2h 4m
2024-08-14 23:32 en/3.13 38m
2024-08-15 00:11 zh-tw/3.14 1h 46m
2024-08-15 01:59 zh-cn/3.14 1h 36m
2024-08-15 03:37 uk/3.14 3m
2024-08-15 03:42 tr/3.14 1h 58m
2024-08-15 05:42 pt-br/3.14 50m
2024-08-15 06:34 pl/3.14 43m
2024-08-15 07:18 ko/3.14 1h 1m
2024-08-15 08:21 ja/3.14 1h 44m
2024-08-15 10:07 it/3.14 39m
2024-08-15 10:48 id/3.14 49m
2024-08-15 12:10 es/3.14 2h 15m
2024-08-15 14:27 en/3.14 38m
2024-08-15 16:07 zh-tw/3.12 1h 56m
2024-08-15 18:06 zh-cn/3.12 1h 36m
2024-08-15 19:44 uk/3.12 3m
2024-08-15 19:48 tr/3.12 2h 6m
2024-08-15 21:56 pt-br/3.12 43m
2024-08-15 22:41 pl/3.12 38m
2024-08-15 23:21 ko/3.12 55m

We're spending a LOT of time churning out those PDFs: an hour or two per language/version.


Stepping back a moment, the cron entry is:

7 * * * * /srv/docsbuild/venv/bin/python /srv/docsbuild/scripts/build_docs.py

This script builds all languages and versions, and currently takes about 30 hours for a full batch.

The cron triggers at 7 minutes past the hour. If there's a build currently running, the new one just ends.

Suggestion: split HTML and PDF builds

I suggest we have two cron jobs. One that builds only HTML, the other that does everything else except HTML.

  • We'd allow these to run at the same time. A full HTML batch should be very quick. For example, the Ukrainian build is HTML only and takes 3 minutes. 13 languages x 3 minutes = 39 minutes.

  • We'd get docs HTML updates out the door quickly: ~30 minutes instead of ~30 hours! I also expect many of the next hourly triggers would not to need to rebuild anything, because there's less likely to be new docs changes after one hour compared to 30 hours.

  • I expect the other cron job that does non-HTML would still take about as long as now, as it's mostly churning out latex files on a single process. But we're more efficiently using the other CPUs for HTML.

  • I don't have download numbers for the PDFs etc, but I expect they're used much less than the HTML. And HTML is read live on the web right now, others are downloaded for reference and will (maybe) be re-downloaded at some later date.

In fact, I just spotted that #127 / python/psf-salt#236 said we used to build PDFs daily and the docs hourly. That PR was merged two years ago, shall we go back to this?

@AA-Turner
Copy link
Member

build PDFs daily and the docs hourly

I would even suggest building PDFs every 36/48 hours. The main problem with building PDFs less often seems to have been new releases (especially .0) don't have PDF versions at release date, but this seems surmountable.

It seems that we could run multiple latexmk processes for each build (ref: https://tex.stackexchange.com/a/699204) which might improve things -- I'll try and have a look if no one beats me to it.

A

@jfbu
Copy link

jfbu commented Aug 17, 2024

It seems that we could run multiple latexmk processes for each build (ref: https://tex.stackexchange.com/a/699204) which might improve things -- I'll try and have a look if no one beats me to it.

Sounds promising. I can not really test, but wouldn't -j option of make (in the builddir) help here?

I tried running directly latexmk as in https://tex.stackexchange.com/a/699204 but on my system it does not exit once job completes one has to hit RET; besides one should not run it directly so I tried adding the & inside the Makefile rule, same issue, then I tried & with make foo.pdf &, make foo2.pdf & again same issue, and finally -j appears to work: make -j all-pdf in the latex builddir.

But here it should be I guess the with the largest .tex files first so make -j library.pdf c-api.pdf reference.pdf <here the others> (in the latex builddir or with -C option) and not this make -j all-pdf I tried.

(I already admitted being on a single core system, so I can not vouch this will use multiple cores in real life).

As per my earlier comment about -xelatex option, see sphinx-doc/sphinx#12636. Best sure way to gain some time is to run the whole build in a TeXLive2019 environment not a TeXLive2024 one. Of course if that is compatible with extras from conf.py (fonts configuration?) which I have not checked here. Core Sphinx (even latest current version) produces exactly same result in a TL2019 based environment as in a TL2024 one.

@AA-Turner
Copy link
Member

AA-Turner commented Aug 17, 2024

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

@jfbu
Copy link

jfbu commented Aug 17, 2024

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 »

@jfbu
Copy link

jfbu commented Aug 17, 2024

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.

@hugovk
Copy link
Member

hugovk commented Aug 25, 2024

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()

@jfbu
Copy link

jfbu commented Aug 25, 2024

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).

@hugovk
Copy link
Member

hugovk commented Aug 25, 2024

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.)

@jfbu
Copy link

jfbu commented Aug 25, 2024

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.

@hugovk
Copy link
Member

hugovk commented Sep 18, 2024

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):

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

@AA-Turner
Copy link
Member

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

@hugovk
Copy link
Member

hugovk commented Sep 23, 2024

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:

@merwok
Copy link
Member

merwok commented Oct 1, 2024

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

@AA-Turner
Copy link
Member

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

@AA-Turner
Copy link
Member

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

@hugovk
Copy link
Member

hugovk commented Oct 2, 2024

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!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests