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

Investigate performance concerns raised between 1.4 and 4.3 #324

Closed
jaraco opened this issue Jun 8, 2021 · 8 comments
Closed

Investigate performance concerns raised between 1.4 and 4.3 #324

jaraco opened this issue Jun 8, 2021 · 8 comments
Labels
invalid This doesn't seem right

Comments

@jaraco
Copy link
Member

jaraco commented Jun 8, 2021

In bpo-44246, @asottile writes:

here's the performance regressions, they affect any callers of distributions() and are even worse on callers of the new apis.

a call to distributions() is about 3x slower than in 3.9

here is the setup I am using:

virtualenv venv39 -ppython3.9
venv39/bin/pip install flake8 pytest twine pre-commit
virtualenv venv310 -ppython3.10
venv310/bin/pip install flake8 pytest twine pre-commit

to test just the distributions() call I'm using the following:

$ venv39/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points()'
20 loops, best of 20: 12.5 msec per loop
$ venv310/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points()'
20 loops, best of 20: 36.7 msec per loop

this is a less-extreme example, many applications have more dependencies installed -- but even in this case this is adding ~24ms startup to any application using entry_points() -- and it gets worse

the return value of entry_points() alone isn't all that useful, next an application needs to retrieve its entry points. let's start for the somewhat normal case of retrieving a single category of entry points:

$ venv39/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points()["flake8.extension"]'
20 loops, best of 20: 12.7 msec per loop
$ venv310/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points(name="flake8.extension")'
20 loops, best of 20: 37.1 msec per loop
$ venv310/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points().select(group="flake8.extension")'
20 loops, best of 20: 37.1 msec per loop

again, 3x slower and very real time to the end user (~24-25ms)

now let's show an example usage that something like flake8 uses where multiple groups are requested (this is common for apps and plugin systems which provide multiple distinct functionalities)

$ venv39/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'eps = entry_points(); eps["flake8.extension"]; eps["flake8.report"]'
 
20 loops, best of 20: 12.6 msec per loop
$ venv310/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'eps = entry_points(); eps.select(group="flake8.extension"); eps.select(group="flake8.report")'
20 loops, best of 20: 38.2 msec per loop

also slower, but an additional ms per call to .select(...)

and it only gets worse with more and more packages installed

here's the versions I'm using to ensure they are up to date:

$ venv39/bin/python --version --version
Python 3.9.5 (default, May 19 2021, 11:32:47) 
[GCC 9.3.0]
$ venv310/bin/python --version --version
Python 3.10.0b2 (default, Jun  2 2021, 00:22:18) [GCC 9.3.0]

Python 3.10.0b2 maps to importlib_metadata 4.3 and Python 3.9.5 maps to importlib_metadata 1.4. Let's investigate which factors affect the performance and what use cases.

@jaraco
Copy link
Member Author

jaraco commented Jun 20, 2021

In jaraco/pytest-perf 0.2, I've made some progress toward having a pytest plugin that can take a suite of tests and compare them against the main branch. I'm hoping to use that to evaluate options to address the reported concerns.

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

In e796bcc, I've added a test that models the reported regression. The test added here runs the aforementioned commands through timeit and then compares the results.

However, on both my machine and in CI runs such as this one, the output from the test looks something like this:

exercises.py:entry_points_selected_perf: 0:00:00.004220 (+-1 day, 23:59:59.990620, -69%)

That result indicates that the local code took 4.2ms and that was 69% faster than the code in importlib_metadata 1.4, contradicting the original report.

To be sure, pytest-perf is new and could contain bugs (I had to fix jaraco/pytest-perf#2 to ensure the correct code was being called). It's also conceivable that there are differences in Python 3.10 and 3.9 that are affecting the performance.

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

Re-reading the report, I see that there were additional dependencies indicated that weren't present in my attempt to repro. Adding these dependencies did add a couple of ms to the load time, but did not affect the percentage difference:

exercises.py:entry_points_selected_perf: 0:00:00.006230 (+-1 day, 23:59:59.986530, -68%)

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

If you want to try it for yourself, just clone the eval/324-entry-points-selected-perf branch and run tox -- -k entry_points_selected_perf -p no:cov.

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

Just to check my assumptions on how the test is measuring and reporting, I added the following diff to inject 10ms of slowness into each trial:

diff --git a/exercises.py b/exercises.py
index 0c997be3582..f1a83a90aa4 100644
--- a/exercises.py
+++ b/exercises.py
@@ -46,6 +46,8 @@ def entry_points_selected_perf():
     try:
         eps.select(group="flake8.extension")
         eps.select(group="flake8.report")
+        import time
+        time.sleep(.01)
     except AttributeError:
         eps["flake8.extension"]
         eps["flake8.report"]

And then ran the tests again. This time, pytest-perf reports that the experiment took 21ms and was 50% slower than the control:

exercises.py:entry_points_selected_perf: 0:00:00.021300 (+0:00:00.007100, 50%)

That's fairly consistent, at least within an order of magnitude.

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

In 4de84f8, I add some assertions. I was going to assert that the lengths of the entry points were the same, but they're not the same, possibly due to deduplication of distributions (although that shouldn't be the case either, so maybe that's a clue).

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

Running the tests on Python 3.10, the performance is even better, so that doesn't explain the reported regression:

importlib_metadata eval/324-entry-points-selected-perf $ tox -r -e py310 -- -k entry_points_selected_perf -p no:cov | grep 'perf:'
exercises.py:entry_points_selected_perf: 0:00:00.003400 (+-1 day, 23:59:59.991800, -71%)

@jaraco
Copy link
Member Author

jaraco commented Jun 27, 2021

Re-running the exact commands from the OP using Python 3.9.5 and Python 3.10.0b3, I get the opposite results to those reported (Python 3.10 is > 4x faster):

draft $ virtualenv -p python3.9 venv39
created virtual environment CPython3.9.5.final.0-64 in 313ms
  creator CPython3Posix(dest=/Users/jaraco/draft/venv39, clear=False, no_vcs_ignore=False, global=False)
  seeder FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/Users/jaraco/Library/Application Support/virtualenv)
    added seed packages: pip==21.0.1, setuptools==57.0.0, wheel==0.36.2
  activators BashActivator,CShellActivator,FishActivator,PowerShellActivator,PythonActivator,XonshActivator
draft $ virtualenv -p python3.10 venv310
created virtual environment CPython3.10.0.beta.3-64 in 397ms
  creator CPython3Posix(dest=/Users/jaraco/draft/venv310, clear=False, no_vcs_ignore=False, global=False)
  seeder FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/Users/jaraco/Library/Application Support/virtualenv)
    added seed packages: pip==21.1.2, setuptools==57.0.0, wheel==0.36.2
  activators BashActivator,CShellActivator,FishActivator,PowerShellActivator,PythonActivator,XonshActivator
draft $ venv39/bin/pip install flake8 pytest twine pre-commit
Collecting flake8
  Using cached flake8-3.9.2-py2.py3-none-any.whl (73 kB)
Collecting pytest
  Using cached pytest-6.2.4-py3-none-any.whl (280 kB)
Collecting twine
  Using cached twine-3.4.1-py3-none-any.whl (34 kB)
Collecting pre-commit
  Using cached pre_commit-2.13.0-py2.py3-none-any.whl (190 kB)
Collecting pyflakes<2.4.0,>=2.3.0
  Using cached pyflakes-2.3.1-py2.py3-none-any.whl (68 kB)
Collecting pycodestyle<2.8.0,>=2.7.0
  Using cached pycodestyle-2.7.0-py2.py3-none-any.whl (41 kB)
Collecting mccabe<0.7.0,>=0.6.0
  Using cached mccabe-0.6.1-py2.py3-none-any.whl (8.6 kB)
Collecting cfgv>=2.0.0
  Using cached cfgv-3.3.0-py2.py3-none-any.whl (7.3 kB)
Collecting virtualenv>=20.0.8
  Using cached virtualenv-20.4.7-py2.py3-none-any.whl (7.2 MB)
Collecting toml
  Using cached toml-0.10.2-py2.py3-none-any.whl (16 kB)
Collecting pyyaml>=5.1
  Using cached PyYAML-5.4.1-cp39-cp39-macosx_10_9_x86_64.whl (259 kB)
Collecting identify>=1.0.0
  Using cached identify-2.2.10-py2.py3-none-any.whl (98 kB)
Collecting nodeenv>=0.11.1
  Using cached nodeenv-1.6.0-py2.py3-none-any.whl (21 kB)
Collecting six<2,>=1.9.0
  Using cached six-1.16.0-py2.py3-none-any.whl (11 kB)
Collecting filelock<4,>=3.0.0
  Using cached filelock-3.0.12-py3-none-any.whl (7.6 kB)
Collecting appdirs<2,>=1.4.3
  Using cached appdirs-1.4.4-py2.py3-none-any.whl (9.6 kB)
Collecting distlib<1,>=0.3.1
  Using cached distlib-0.3.2-py2.py3-none-any.whl (338 kB)
Collecting pluggy<1.0.0a1,>=0.12
  Using cached pluggy-0.13.1-py2.py3-none-any.whl (18 kB)
Collecting packaging
  Using cached packaging-20.9-py2.py3-none-any.whl (40 kB)
Collecting py>=1.8.2
  Using cached py-1.10.0-py2.py3-none-any.whl (97 kB)
Collecting attrs>=19.2.0
  Using cached attrs-21.2.0-py2.py3-none-any.whl (53 kB)
Collecting iniconfig
  Using cached iniconfig-1.1.1-py2.py3-none-any.whl (5.0 kB)
Collecting pkginfo>=1.4.2
  Using cached pkginfo-1.7.0-py2.py3-none-any.whl (25 kB)
Collecting keyring>=15.1
  Using cached keyring-23.0.1-py3-none-any.whl (33 kB)
Collecting requests-toolbelt!=0.9.0,>=0.8.0
  Using cached requests_toolbelt-0.9.1-py2.py3-none-any.whl (54 kB)
Collecting tqdm>=4.14
  Using cached tqdm-4.61.1-py2.py3-none-any.whl (75 kB)
Collecting requests>=2.20
  Using cached requests-2.25.1-py2.py3-none-any.whl (61 kB)
Collecting importlib-metadata>=3.6
  Using cached importlib_metadata-4.6.0-py3-none-any.whl (17 kB)
Collecting readme-renderer>=21.0
  Using cached readme_renderer-29.0-py2.py3-none-any.whl (15 kB)
Collecting rfc3986>=1.4.0
  Using cached rfc3986-1.5.0-py2.py3-none-any.whl (31 kB)
Collecting colorama>=0.4.3
  Using cached colorama-0.4.4-py2.py3-none-any.whl (16 kB)
vCollecting zipp>=0.5
  Using cached zipp-3.4.1-py3-none-any.whl (5.2 kB)
eCollecting docutils>=0.13.1
  Using cached docutils-0.17.1-py2.py3-none-any.whl (575 kB)
nCollecting Pygments>=2.5.1
  Using cached Pygments-2.9.0-py3-none-any.whl (1.0 MB)
vCollecting bleach>=2.1.0
  Using cached bleach-3.3.0-py2.py3-none-any.whl (283 kB)
Collecting webencodings
  Using cached webencodings-0.5.1-py2.py3-none-any.whl (11 kB)
Collecting chardet<5,>=3.0.2
  Using cached chardet-4.0.0-py2.py3-none-any.whl (178 kB)
Collecting urllib3<1.27,>=1.21.1
  Using cached urllib3-1.26.6-py2.py3-none-any.whl (138 kB)
Collecting certifi>=2017.4.17
  Using cached certifi-2021.5.30-py2.py3-none-any.whl (145 kB)
Collecting idna<3,>=2.5
  Using cached idna-2.10-py2.py3-none-any.whl (58 kB)
3Collecting pyparsing>=2.0.2
  Using cached pyparsing-2.4.7-py2.py3-none-any.whl (67 kB)
1Installing collected packages: pyparsing, zipp, webencodings, urllib3, six, packaging, idna, chardet, certifi, requests, Pygments, importlib-metadata, filelock, docutils, distlib, bleach, appdirs, virtualenv, tqdm, toml, rfc3986, requests-toolbelt, readme-renderer, pyyaml, pyflakes, pycodestyle, py, pluggy, pkginfo, nodeenv, mccabe, keyring, iniconfig, identify, colorama, cfgv, attrs, twine, pytest, pre-commit, flake8
0/bin/pip install flake8Successfully installed Pygments-2.9.0 appdirs-1.4.4 attrs-21.2.0 bleach-3.3.0 certifi-2021.5.30 cfgv-3.3.0 chardet-4.0.0 colorama-0.4.4 distlib-0.3.2 docutils-0.17.1 filelock-3.0.12 flake8-3.9.2 identify-2.2.10 idna-2.10 importlib-metadata-4.6.0 iniconfig-1.1.1 keyring-23.0.1 mccabe-0.6.1 nodeenv-1.6.0 packaging-20.9 pkginfo-1.7.0 pluggy-0.13.1 pre-commit-2.13.0 py-1.10.0 pycodestyle-2.7.0 pyflakes-2.3.1 pyparsing-2.4.7 pytest-6.2.4 pyyaml-5.4.1 readme-renderer-29.0 requests-2.25.1 requests-toolbelt-0.9.1 rfc3986-1.5.0 six-1.16.0 toml-0.10.2 tqdm-4.61.1 twine-3.4.1 urllib3-1.26.6 virtualenv-20.4.7 webencodings-0.5.1 zipp-3.4.1
 pyWARNING: You are using pip version 21.0.1; however, version 21.1.3 is available.
You should consider upgrading via the '/Users/jaraco/draft/venv39/bin/python -m pip install --upgrade pip' command.
tesdraft $ venv310/bin/pip install flake8 pytest twine pre-commit
Collecting flake8
  Using cached flake8-3.9.2-py2.py3-none-any.whl (73 kB)
Collecting pytest
  Using cached pytest-6.2.4-py3-none-any.whl (280 kB)
Collecting twine
  Using cached twine-3.4.1-py3-none-any.whl (34 kB)
Collecting pre-commit
  Using cached pre_commit-2.13.0-py2.py3-none-any.whl (190 kB)
Collecting pyflakes<2.4.0,>=2.3.0
  Using cached pyflakes-2.3.1-py2.py3-none-any.whl (68 kB)
Collecting pycodestyle<2.8.0,>=2.7.0
  Using cached pycodestyle-2.7.0-py2.py3-none-any.whl (41 kB)
Collecting mccabe<0.7.0,>=0.6.0
  Using cached mccabe-0.6.1-py2.py3-none-any.whl (8.6 kB)
Collecting iniconfig
  Using cached iniconfig-1.1.1-py2.py3-none-any.whl (5.0 kB)
Collecting packaging
  Using cached packaging-20.9-py2.py3-none-any.whl (40 kB)
Collecting pluggy<1.0.0a1,>=0.12
  Using cached pluggy-0.13.1-py2.py3-none-any.whl (18 kB)
Collecting py>=1.8.2
  Using cached py-1.10.0-py2.py3-none-any.whl (97 kB)
Collecting attrs>=19.2.0
  Using cached attrs-21.2.0-py2.py3-none-any.whl (53 kB)
Collecting toml
  Using cached toml-0.10.2-py2.py3-none-any.whl (16 kB)
Collecting rfc3986>=1.4.0
  Using cached rfc3986-1.5.0-py2.py3-none-any.whl (31 kB)
Collecting readme-renderer>=21.0
  Using cached readme_renderer-29.0-py2.py3-none-any.whl (15 kB)
Collecting pkginfo>=1.4.2
  Using cached pkginfo-1.7.0-py2.py3-none-any.whl (25 kB)
Collecting importlib-metadata>=3.6
  Using cached importlib_metadata-4.6.0-py3-none-any.whl (17 kB)
Collecting tqdm>=4.14
  Using cached tqdm-4.61.1-py2.py3-none-any.whl (75 kB)
Collecting requests-toolbelt!=0.9.0,>=0.8.0
  Using cached requests_toolbelt-0.9.1-py2.py3-none-any.whl (54 kB)
Collecting requests>=2.20
  Using cached requests-2.25.1-py2.py3-none-any.whl (61 kB)
Collecting colorama>=0.4.3
  Using cached colorama-0.4.4-py2.py3-none-any.whl (16 kB)
Collecting keyring>=15.1
  Using cached keyring-23.0.1-py3-none-any.whl (33 kB)
Collecting zipp>=0.5
  Using cached zipp-3.4.1-py3-none-any.whl (5.2 kB)
Collecting bleach>=2.1.0
  Using cached bleach-3.3.0-py2.py3-none-any.whl (283 kB)
Collecting docutils>=0.13.1
  Using cached docutils-0.17.1-py2.py3-none-any.whl (575 kB)
Collecting six
  Using cached six-1.16.0-py2.py3-none-any.whl (11 kB)
Collecting Pygments>=2.5.1
  Using cached Pygments-2.9.0-py3-none-any.whl (1.0 MB)
Collecting webencodings
  Using cached webencodings-0.5.1-py2.py3-none-any.whl (11 kB)
Collecting idna<3,>=2.5
  Using cached idna-2.10-py2.py3-none-any.whl (58 kB)
Collecting certifi>=2017.4.17
  Using cached certifi-2021.5.30-py2.py3-none-any.whl (145 kB)
Collecting urllib3<1.27,>=1.21.1
  Using cached urllib3-1.26.6-py2.py3-none-any.whl (138 kB)
Collecting chardet<5,>=3.0.2
  Using cached chardet-4.0.0-py2.py3-none-any.whl (178 kB)
Collecting identify>=1.0.0
  Using cached identify-2.2.10-py2.py3-none-any.whl (98 kB)
Collecting cfgv>=2.0.0
  Using cached cfgv-3.3.0-py2.py3-none-any.whl (7.3 kB)
Collecting nodeenv>=0.11.1
  Using cached nodeenv-1.6.0-py2.py3-none-any.whl (21 kB)
Collecting pyyaml>=5.1
  Using cached PyYAML-5.4.1-cp310-cp310-macosx_10_9_universal2.whl
Collecting virtualenv>=20.0.8
  Using cached virtualenv-20.4.7-py2.py3-none-any.whl (7.2 MB)
Collecting distlib<1,>=0.3.1
  Using cached distlib-0.3.2-py2.py3-none-any.whl (338 kB)
nCollecting appdirs<2,>=1.4.3
  Using cached appdirs-1.4.4-py2.py3-none-any.whl (9.6 kB)
Collecting filelock<4,>=3.0.0
  Using cached filelock-3.0.12-py3-none-any.whl (7.6 kB)
Collecting pyparsing>=2.0.2
  Using cached pyparsing-2.4.7-py2.py3-none-any.whl (67 kB)
Installing collected packages: pyparsing, zipp, webencodings, urllib3, six, packaging, idna, chardet, certifi, requests, Pygments, importlib-metadata, filelock, docutils, distlib, bleach, appdirs, virtualenv, tqdm, toml, rfc3986, requests-toolbelt, readme-renderer, pyyaml, pyflakes, pycodestyle, py, pluggy, pkginfo, nodeenv, mccabe, keyring, iniconfig, identify, colorama, cfgv, attrs, twine, pytest, pre-commit, flake8
nSuccessfully installed Pygments-2.9.0 appdirs-1.4.4 attrs-21.2.0 bleach-3.3.0 certifi-2021.5.30 cfgv-3.3.0 chardet-4.0.0 colorama-0.4.4 distlib-0.3.2 docutils-0.17.1 filelock-3.0.12 flake8-3.9.2 identify-2.2.10 idna-2.10 importlib-metadata-4.6.0 iniconfig-1.1.1 keyring-23.0.1 mccabe-0.6.1 nodeenv-1.6.0 packaging-20.9 pkginfo-1.7.0 pluggy-0.13.1 pre-commit-2.13.0 py-1.10.0 pycodestyle-2.7.0 pyflakes-2.3.1 pyparsing-2.4.7 pytest-6.2.4 pyyaml-5.4.1 readme-renderer-29.0 requests-2.25.1 requests-toolbelt-0.9.1 rfc3986-1.5.0 six-1.16.0 toml-0.10.2 tqdm-4.61.1 twine-3.4.1 urllib3-1.26.6 virtualenv-20.4.7 webencodings-0.5.1 zipp-3.4.1
WARNING: You are using pip version 21.1.2; however, version 21.1.3 is available.
You should consider upgrading via the '/Users/jaraco/draft/venv310/bin/python -m pip install --upgrade pip' command.
draft $ venv39/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points()'
20 loops, best of 20: 8.54 msec per loop
draft $ venv310/bin/python -m timeit -n 20 -r 20 -s 'from importlib.metadata import entry_points' 'entry_points()'
20 loops, best of 20: 2.34 msec per loop

At this point, I don't believe the report is valid, or maybe it was fixed by incorporating the performance fixes that I'd advised were added in Python 3.10b3 and importlib_metadata 4.3.

@jaraco jaraco closed this as completed Jun 27, 2021
@jaraco jaraco added the invalid This doesn't seem right label Jun 27, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
invalid This doesn't seem right
Projects
None yet
Development

No branches or pull requests

1 participant