GeezerVison is showing github.com — Incremental GC causes a significant slowdown for Sphinx · Issue #124567 · python/cpython
Incremental GC causes a significant slowdown for Sphinx #124567DescriptionBug report
A significant performance regression in Sphinx caused by changes in CPython 3.13
Here is a script that does the following things:
- Replaces the contents of all CPython documentation files except
Doc/library/typing.rst with simply "foo"
- Creates a virtual environment
- Installs our doc dependencies into the environment (making sure that we use pure-Python versions for all doc dependencies rather than built wheels that might include C extensions)
- Times how long it takes to build the docs using that environment
- Restores all the modified docs files and deletes the virtual environment again
The script
import contextlib
import shutil
import subprocess
import time
import venv
from pathlib import Path
def run(args):
try:
subprocess.run(args, check=True, capture_output=True, text=True)
except subprocess.CalledProcessError as e:
print(e.stdout)
print(e.stderr)
raise
with contextlib.chdir("Doc"):
try:
for path in Path(".").iterdir():
if path.is_dir() and not str(path).startswith("."):
for doc_path in path.rglob("*.rst"):
if doc_path != Path("library/typing.rst"):
doc_path.write_text("foo")
venv.create(".venv", with_pip=True)
run([
".venv/bin/python",
"-m",
"pip",
"install",
"-r",
"requirements.txt",
"--no-binary=':all:'",
])
start = time.perf_counter()
run([
".venv/bin/python",
"-m",
"sphinx",
"-b",
"html",
".",
"build/html",
"library/typing.rst",
])
print(time.perf_counter() - start)
shutil.rmtree(".venv")
shutil.rmtree("build")
finally:
subprocess.run(["git", "restore", "."], check=True, capture_output=True)
Using a PGO-optimized build with LTO enabled, the script reports that there is a significant performance regression in Sphinx's parsing and building of library/typing.rst between v3.13.0a1 and 909c6f7:
- On
v13.0a1 the script reports a Sphinx build time of between 1.27s and 1.29s (I ran the script several times)
- On ede1504, a Sphinx build time of between 1.76 and 1.82s is reported by the script (a roughly 48% regression).
A similar regression is reported in this (much slower) variation of the script that builds the entire set of CPython's documentation rather than just library/typing.rst.
More comprehensive variation of the script
import contextlib
import shutil
import subprocess
import time
import venv
def run(args):
subprocess.run(args, check=True, text=True)
with contextlib.chdir("Doc"):
venv.create(".venv", with_pip=True)
run([
".venv/bin/python",
"-m",
"pip",
"install",
"-r",
"requirements.txt",
"--no-binary=':all:'",
])
start = time.perf_counter()
run([
".venv/bin/python",
"-m",
"sphinx",
"-b",
"html",
".",
"build/html",
])
print(time.perf_counter() - start)
shutil.rmtree(".venv")
shutil.rmtree("build")
The PGO-optimized timings for building the entire CPython documentation is as follows:
This indicates a 38% performance regression for building the entire set of CPython's documentation.
Cause of the performance regression
This performance regression was initially discovered in #118891: in our own CI, we use a fresh build of CPython in our Doctest CI workflow (since otherwise, we wouldn't be testing the tip of the main branch), and it was observed that the CI job was taking significantly longer on the 3.13 branch than the 3.12 branch. In the context of our CI, the performance regression is even worse, because of the fact that our Doctest CI workflow uses a debug build rather than a PGO-optimized build, and the regression is even more pronounced in a Debug build.
Using a debug build, I used the first script posted above to bisect the performance regression to commit 1530932 (below), which seemed to cause a performance regression of around 300% in a debug build
15309329b65a285cb7b3071f0f08ac964b61411b is the first bad commit
commit 15309329b65a285cb7b3071f0f08ac964b61411b
Author: Mark Shannon <[email protected]>
Date: Wed Mar 20 08:54:42 2024 +0000
GH-108362: Incremental Cycle GC (GH-116206)
Doc/whatsnew/3.13.rst | 30 +
Include/internal/pycore_gc.h | 41 +-
Include/internal/pycore_object.h | 18 +-
Include/internal/pycore_runtime_init.h | 8 +-
Lib/test/test_gc.py | 72 +-
.../2024-01-07-04-22-51.gh-issue-108362.oB9Gcf.rst | 12 +
Modules/gcmodule.c | 25 +-
Objects/object.c | 21 +
Objects/structseq.c | 5 +-
Python/gc.c | 806 +++++++++++++--------
Python/gc_free_threading.c | 23 +-
Python/import.c | 2 +-
Python/optimizer.c | 2 +-
Tools/gdb/libpython.py | 7 +-
14 files changed, 684 insertions(+), 388 deletions(-)
create mode 100644 Misc/NEWS.d/next/Core and Builtins/2024-01-07-04-22-51.gh-issue-108362.oB9Gcf.rst
Performance was then significantly improved by commit e28477f (below), but it's unfortunately still the case that Sphinx is far slower on Python 3.13 than on Python 3.12:
commit e28477f214276db941e715eebc8cdfb96c1207d9
Author: Mark Shannon <[email protected]>
Date: Fri Mar 22 18:43:25 2024 +0000
GH-117108: Change the size of the GC increment to about 1% of the total heap size. (GH-117120)
Include/internal/pycore_gc.h | 3 +-
Lib/test/test_gc.py | 35 +++++++++++++++-------
.../2024-03-21-12-10-11.gh-issue-117108._6jIrB.rst | 3 ++
Modules/gcmodule.c | 2 +-
Python/gc.c | 30 +++++++++----------
Python/gc_free_threading.c | 2 +-
6 files changed, 47 insertions(+), 28 deletions(-)
create mode 100644 Misc/NEWS.d/next/Core and Builtins/2024-03-21-12-10-11.gh-issue-117108._6jIrB.rst
See #118891 (comment) for more details on the bisection results.
Profiling by @nascheme in #118891 (comment) and #118891 (comment) also confirms that Sphinx spends a significant amount of time in the GC, so it seems very likely that the changes to introduce an incremental GC in Python 3.13 is the cause of this performance regression.
Cc. @markshannon for expertise on the new incremental GC, and cc. @hugovk / @AA-Turner for Sphinx expertise.
CPython versions tested on:
3.12, 3.13, CPython main branch
Operating systems tested on:
macOS
Linked PRs
Reacted by Vasily Ryabov Reacted by Kerim Kabirov Activitypicnixz commented on Sep 26, 2024 I think I wanted to investigate it in sphinx-doc/sphinx#12181 but then I didn't have the motivation nor the time... (and we wanted to avoid keeping opened issues for too long). The root cause was the memory usage for docutils that increased a lot so this might be the reason why we are also seeing those slowdowns. Reacted by Alex Waygood and Kerim Kabirov AlexWaygood commented on Sep 26, 2024
I think I wanted to investigate it in sphinx-doc/sphinx#12181 but then I didn't have the motivation nor the time... (and we wanted to avoid keeping opened issues for too long).
Yes, @AA-Turner mentioned as much in #118891 (comment). This seems like the kind of issue that could cause slowdowns for other workloads as well as Sphinx, however. (But I'll defer to our performance and GC experts on if there are obvious ways to mitigate it.) AlexWaygood commented on Sep 26, 2024 Prompted by @ned-deily, I reran my PGO-optimized timings using --with-lto=full --enable-optimizations builds rather than simply --with-lto --enable-optimizations builds. (Since I'm benchmarking using a Mac, this could have been relevant.) The timings on v3.13.0a1 and main using this build configuration were essentially identical to the ones I reported above, however. Reacted by Carol Willing and Vasily Ryabov willingc commented on Sep 26, 2024 hauntsaninja commented on Sep 26, 2024 Could be cool to make the sphinx build a pyperformance benchmark (I think there might be a docutils pyperf benchmark, wonder if that saw a regression) JelleZijlstra commented on Sep 26, 2024 Reacted by Alex Waygood and Carol Willing picnixz commented on Sep 26, 2024
According to Michael that benchmark didn't show a regression
There is a bit of a regression actually, at least in the memory usage as reported by faster-cpython/ideas#668 (roughly a 20% increase of memory). I don't think that's all there is to actually make Sphinx slower. AA-Turner commented on Sep 26, 2024 Thanks Alex for the excellent write-up. A note for reproduction, in my local tests the slowdown could be reproduced just in the parsing step, so you can use 'dummy' instead of 'html' in the reproduction script to save time (as no HTML files are produced).
library/typing.rst
Interestingly I found that when building just that document, timings were broadly the same. However when building everything, 3.13.0a5 was consistently 1.6x faster than 3.13.0a6 (using the built optimised releases from https://www.python.org/downloads/ for Windows, 64 bit).
Could be cool to make the sphinx build a pyperformance benchmark
When I added the Docutils benchmark, Michael Droettboom requested that I/O variables (reading & writing files) be removed as it adds too much noise. There isn't a good way to avoid I/O in Sphinx, unlike with Docutils, unfortunatley. I would be keen to add Sphinx to the benchmark suite.
Looks like it builds a bunch of RST files
Docutils' documentation, we can't use Python's as the Python documentation uses Sphinx-only extensions.
A AA-Turner commented on Nov 18, 2024
Do we also need to check how the Sphinx benchmark looks with a PGO-optimized release build relative to 3.13? (The CI doctest job uses a debug build.)
I agree, for completeness we should confirm that the slowdown has gone from release builds (it was always much more pronounced in debug builds).
A mdboom commented on Nov 18, 2024 Reacted by Itamar Oren and Hugo van Kemenade Reacted by Alex Waygood and Hugo van Kemenade AlexWaygood commented on Nov 18, 2024 Performance is also now unchanged for me locally relative to Python 3.13 (or maybe slightly better!) using the script I posted in #118891 (comment):
main (built using --enable-optimisations --with-lto=full): 37.22s- 3.13: 38.15s
Closing as completed. Thanks everybody who helped investigate, and thanks @markshannon for fixing! 🥳 Reacted by Hugo van Kemenade Reacted by Hugo van Kemenade, Adam Turner and Carol Willing Reacted by Hugo van Kemenade and Carol Willing AlexWaygood commented on Nov 19, 2024 Reopening since #126502 was reverted in #126983 due to buildbot failures markshannon commented on Nov 19, 2024 Reacted by Alex Waygood and Hugo van Kemenade Reacted by Alex Waygood
MetadataMetadataStatusShow more project fields
DevelopmentNo branches or pull requestsIssue actions
|