8000 Show elapsed time for build and publishing by hugovk · Pull Request #188 · python/docsbuild-scripts · GitHub
[go: up one dir, main page]
Skip to content

Sho 8000 w elapsed time for build and publishing #188

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.

Sign up for GitHub

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

Jump to bottom
Merged
merged 11 commits into from
Sep 17, 2024
Merged

Show elapsed time for build and publishing #188

merged 11 commits into from
Sep 17, 2024

Conversation

hugovk
Copy link
Member
@hugovk hugovk commented Aug 15, 2024

Helps #169.

The logs for a single language/version look like this:

logs 
2024-08-14 14:01:15,870 INFO ja/3.12: Running.
2024-08-14 14:01:15,871 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython show-ref -s origin/3.12'
2024-08-14 14:01:15,874 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython reset --hard 344a7b535bb725a7ea144648a6a3bc3ce8485e2c --'
2024-08-14 14:01:15,905 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython clean -dfqx'
2024-08-14 14:01:16,080 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES fetch'
2024-08-14 14:01:16,345 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES branch -r'
2024-08-14 14:01:16,349 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES show-ref -s origin/3.11'
2024-08-14 14:01:16,352 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES reset --hard 71404d22de96db3df16e11a1d92c39f58cb746f5 --'
2024-08-14 14:01:16,916 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES clean -dfqx'
2024-08-14 14:01:17,039 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython rev-parse HEAD'
2024-08-14 14:01:17,042 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES rev-parse HEAD'
2024-08-14 14:01:17,044 INFO ja/3.12: Should rebuild: new translations (from 61bd824895952478350bad88edc205741af324e2 to 71404d22de96db3df16e11a1d92c39f58cb746f5)
2024-08-14 14:01:17,045 DEBUG ja/3.12: Run: '/srv/docsbuild/venv/bin/python -m venv /srv/docsbuild/venv-3.12'
2024-08-14 14:01:19,328 DEBUG ja/3.12: Run: '/srv/docsbuild/venv-3.12/bin/python -m pip install --upgrade python-docs-theme jieba -rrequirements.txt'
2024-08-14 14:01:20,398 DEBUG ja/3.12: Run: '/srv/docsbuild/venv-3.12/bin/python -m pip freeze --all'
2024-08-14 14:01:20,830 INFO ja/3.12: Build start.
2024-08-14 14:01:21,130 INFO ja/3.12: Running make autobuild-stable
2024-08-14 14:01:21,131 DEBUG ja/3.12: Run: "sed -i 's/ *-A switchers=1//' /srv/docsbuild/cpython/Doc/Makefile"
2024-08-14 14:01:21,137 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}\\\\makeatot
8000
her\\\\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-14 14:07:01,512 INFO: Another builder is running... dying...
2024-08-14 15:07:02,088 INFO: Another builder is running... dying...
2024-08-14 15:33:21,379 DEBUG ja/3.12: Run: 'mkdir -p /var/log/docsbuild'
2024-08-14 15:33:21,382 DEBUG ja/3.12: Run: 'chgrp -R docs /var/log/docsbuild'
2024-08-14 15:33:23,090 INFO ja/3.12: Build done.
2024-08-14 15:33:23,091 INFO ja/3.12: Publishing start.
2024-08-14 15:33:23,091 DEBUG ja/3.12: Run: 'chgrp -R docs /srv/docs.python.org/ja'
2024-08-14 15:33:23,177 DEBUG ja/3.12: Run: 'chgrp -R docs /srv/docs.python.org/ja/3.12'
2024-08-14 15:33:24,480 INFO ja/3.12: Copying HTML files to /srv/docs.python.org/ja/3.12
2024-08-14 15:33:24,481 DEBUG ja/3.12: Run: 'chown -R :docs /srv/docsbuild/cpython/Doc/build/html'
2024-08-14 15:33:24,488 DEBUG ja/3.12: Run: 'chmod -R o+r /srv/docsbuild/cpython/Doc/build/html'
2024-08-14 15:33:24,498 DEBUG ja/3.12: Run: "find /srv/docsbuild/cpython/Doc/build/html -type d -exec chmod o+x '{}' ';'"
2024-08-14 15:33:24,547 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-14 15:33:24,965 DEBUG ja/3.12: Copying dist files.
2024-08-14 15:33:24,965 DEBUG ja/3.12: Run: 'chown -R :docs /srv/docsbuild/cpython/Doc/dist'
2024-08-14 15:33:24,967 DEBUG ja/3.12: Run: 'chmod -R o+r /srv/docsbuild/cpython/Doc/dist'
2024-08-14 15:33:24,969 DEBUG ja/3.12: Run: 'mkdir -m o+rx -p /srv/docs.python.org/ja/3.12/archives'
2024-08-14 15:33:24,971 DEBUG ja/3.12: Run: 'chown :docs /srv/docs.python.org/ja/3.12/archives'
2024-08-14 15:33:24,973 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-14 15:33:25,214 INFO ja/3.12: 886 files changed
2024-08-14 15:33:25,214 DEBUG ja/3.12: Run: 'find -L /srv/docs.python.org -samefile /srv/docs.python.org/ja/3.12'
2024-08-14 15:33:27,813 DEBUG ja/3.12: Purging https://docs.python.org/ja/3/ from CDN
2024-08-14 15:33:27,814 DEBUG ja/3.12: Starting new HTTPS connection (1): docs.python.org:443
2024-08-14 15:33:27,858 DEBUG ja/3.12: https://docs.python.org:443 "PURGE /ja/3/ HTTP/1.1" 200 53
<snip 5316 lines>
2024-08-14 15:34:58,559 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-14 15:34:58,560 DEBUG ja/3.12: Starting new HTTPS connection (1): docs.python.org:443
2024-08-14 15:34:58,615 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 52
2024-08-14 15:34:58,618 INFO ja/3.12: Publishing done
2024-08-14 15:34:58,766 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/cpython rev-parse HEAD'
2024-08-14 15:34:58,770 DEBUG ja/3.12: Run: 'git -C /srv/docsbuild/3.12/locale/ja/LC_MESSAGES rev-parse HEAD'

The longest "start"/"done" times are:

2024-08-14 14:01:20,830 INFO ja/3.12: Build start.
...
2024-08-14 15:33:23,090 INFO ja/3.12: Build done.

This is the longest part of the build, taking about 90 minutes here.

(The slowest command is the actual Sphinx/latex/PDF build: make -C /srv/docsbuild/cpython/Doc ...)

This PR adds a duration to the "done" line:

2024-08-14 15:33:23,090 INFO ja/3.12: Build done (1h 32m 3s).

We also have a "Publishing start"/"Publishing done" pair, which can take a couple of minutes (#184) so I added it there too.

This means we can easily see how long they take in the logs, which will help us analyse build times for #169.

I added tests for the new format_seconds function, plus added it to the CI with linting.

It uses the match statement, new in Python 3.10, so that's the minimum required. The docs server uses 3.10 (although 3.12 is also installed).

AA-Turner
AA-Turner approved these changes Aug 15, 2024
View reviewed changes
@hugovk
Copy link
Member Author
hugovk commented Aug 25, 2024

Updated to wrap "Full build start." / "Full build done (%s)." around the main build_docs() called from main() that builds all the languages and versions combinations.

This allows us to easily grep the daily build logs to see how long the single full build from the cron takes.

willingc
willingc approved these changes Sep 10, 2024
View reviewed changes
Copy link
@willingc willingc left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks @hugovk for adding this and some standard code quality tools that we use in the rest of the docs ecosystem.

@hugovk hugovk merged commit 879433e into python:main Sep 17, 2024
@hugovk hugovk deleted the log-elapsed-time branch September 17, 2024 14:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@willingc willingc willingc approved these changes

@AA-Turner AA-Turner AA-Turner approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
3 participants
@hugovk @willingc @AA-Turner
0