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

Python startup performance regression #72823

Closed
vstinner opened this issue Nov 7, 2016 · 38 comments
Closed

Python startup performance regression #72823

vstinner opened this issue Nov 7, 2016 · 38 comments
Labels
3.7 (EOL) end of life performance Performance or resource usage release-blocker

Comments

@vstinner
Copy link
Member

vstinner commented Nov 7, 2016

BPO 28637
Nosy @rhettinger, @terryjreedy, @gpshead, @vsajip, @vstinner, @tiran, @ned-deily, @ethanfurman, @serhiy-storchaka, @wm75
Files
  • site-not-use-re.patch
  • no_use_re_in_site_py.patch
  • site-not-use-re.patch
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2016-11-14.11:55:02.680>
    created_at = <Date 2016-11-07.23:08:21.740>
    labels = ['3.7', 'release-blocker', 'performance']
    title = 'Python startup performance regression'
    updated_at = <Date 2017-02-17.15:37:46.818>
    user = 'https://github.com/vstinner'

    bugs.python.org fields:

    activity = <Date 2017-02-17.15:37:46.818>
    actor = 'gvanrossum'
    assignee = 'none'
    closed = True
    closed_date = <Date 2016-11-14.11:55:02.680>
    closer = 'vstinner'
    components = []
    creation = <Date 2016-11-07.23:08:21.740>
    creator = 'vstinner'
    dependencies = []
    files = ['45389', '45390', '45391']
    hgrepos = []
    issue_num = 28637
    keywords = ['patch']
    message_count = 38.0
    messages = ['280256', '280258', '280259', '280260', '280261', '280262', '280266', '280267', '280268', '280269', '280271', '280272', '280273', '280274', '280296', '280301', '280302', '280304', '280305', '280306', '280312', '280328', '280346', '280353', '280362', '280370', '280378', '280380', '280383', '280409', '280552', '280558', '280559', '280629', '280636', '280753', '280758', '280760']
    nosy_count = 11.0
    nosy_names = ['rhettinger', 'terry.reedy', 'gregory.p.smith', 'vinay.sajip', 'vstinner', 'christian.heimes', 'ned.deily', 'ethan.furman', 'python-dev', 'serhiy.storchaka', 'wolma']
    pr_nums = []
    priority = 'release blocker'
    resolution = 'fixed'
    stage = None
    status = 'closed'
    superseder = None
    type = 'performance'
    url = 'https://bugs.python.org/issue28637'
    versions = ['Python 3.6', 'Python 3.7']

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 7, 2016

    The changeset 223731925d06 of the issue issue bpo-28082 "use IntFlag for re constants" made Python startup 34% slower:

    • rev 5637c9b4dd4c: Median +- std dev: 19.5 ms +- 0.0 ms
    • rev 223731925d06: Median +- std dev: 26.2 ms +- 0.0 ms

    The change adds "import enum" in Lib/re.py, so the enum module is imported, whereas it wasn't before. It seems like importing enum takes 6.7 ms.

    I propose to revert the change 223731925d06 in Python 3.6 and reopen the issue bpo-28082 to try to find another solution for the re module which doesn't impact Python startup performance.

    @vstinner vstinner added 3.7 (EOL) end of life performance Performance or resource usage release-blocker labels Nov 7, 2016
    @gvanrossum
    Copy link
    Member

    Reverting is reasonable, though it may break some code that started using this in 3.6b1. Such is the life of beta testers. The benefit of using Enum for re constants doesn't seem worth such a big increase in startup time.

    @ethanfurman
    Copy link
    Member

    Ouch, that's a lot slower!

    Victor, can you add the commands you are using for timing so I can work on making enum imports faster?

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 7, 2016

    Ethan Furman added the comment:

    Victor, can you add the commands you are using for timing so I can work on making enum imports faster?

    Results of the python_startup benchmark:
    https://speed.python.org/timeline/#/?exe=4&ben=python_startup&env=1&revs=50&equid=off&quarts=on&extr=on

    This website uses the following benchmark suite:
    https://github.com/python/performance

    You can run the benchmark using:
    python3 -m performance run -b python_startup

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 7, 2016

    Oh, I understood why I had issues to reproduce the startup performance slowdown. When Python is run from the source code using ./python, the re module is not imported. When Python is installed, the re is not imported by default neither:

    haypo@speed-python$ prefix/bin/python3 -c 'import sys; print("re" in sys.modules)'
    False

    BUT when Python is started from a virtual environment (created by the "venv" module), the re module is important by default.

    haypo@speed-python$ venv/bin/python3 -c 'import sys; print("re" in sys.modules)'
    True

    If the site module is not imported, the re module is not imported:

    haypo@speed-python$ venv/bin/python3 -S -c 'import sys; print("re" in sys.modules)'
    False

    The /home/haypo/benchmarks/prefix/lib/python3.6/site.py file is generated by the venv module and contains:

    def venv(...):
        ...
        if candidate_confs:
            import re
            config_line = re.compile(CONFIG_LINE)
            ...

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Nov 7, 2016

    New changeset d903a243c281 by Victor Stinner in branch '3.6':
    Issue bpo-28637: Revert issue bpo-28082, don't import enum in re
    https://hg.python.org/cpython/rev/d903a243c281

    @ned-deily
    Copy link
    Member

    With being this close to release and with two weeks to go until the final beta, it seems a bit premature to immediately revert this without exploring all the alternatives especially since it seems the effects are limited to venvs. In any case, we do need to have a final answer well before the b4 cutoff (2016-11-21). Possible options:

    1. leave the re contents reverted (current status)
    2. find a way to mitigate the performance impact of importing re and enum (perhaps making them builtins in Setup.dist?)
    3. avoid the use of re in site.py venv
    4. others?

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    Possible options:

    1. avoid the use of re in site.py venv

    That would be a tiny but nice enhancement.

    re is a commonly used module. I would prefer to not make its import time slower. Python 3 startup is already something like 3x slower than Python 2. Please don't make it even slower :-( We worked on optimizing Python 3 startup time.

    1. find a way to mitigate the performance impact of importing re and enum (perhaps making them builtins in Setup.dist?)

    I reverted the change, because Guido and Ethan seem to be in favor of a revert, and I don't expect any simple solution for this issue.

    I'm quite sure that importing enum.py is slow. Optimizing enum.py import time is a large task.

    Another option to explore is to delay the creation/instanciation of the re flags, something like lazy module import... but at the module attribute level :-)

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    I remove the release blocker flag since the change was reverted.

    @ned-deily
    Copy link
    Member

    Please leave this as a "release blocker" until we have had a chance to explore all the options for 3.6.0b4. We may still very well decide that reverting is the least bad option but I don't want to rule out other options without some further investigation. We have time and the reverting could be a fairly significant change.

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    Hum strange, the changeset d903a243c281 (the revert) optimized regex_compile: 480 ms (rev 573bc1f9900e) => 403 ms (rev cf7711887b4a).

    But it didn't restore python_startup performance: 26.ms (rev 573bc1f9900e) => 24.6 ms (rev cf7711887b4a).

    Another change made re import slower: revision 88110cfbf4dc of issue bpo-28193. If I also revert this change locally, python_startup performance is restored to 19.6 ms.

    By the way, regex_compile performance is the same with and without the revision 88110cfbf4dc, but the benchmark purges the re cache at each iteration of the benchmark.

    @gvanrossum
    Copy link
    Member

    Agreed.

    --Guido (mobile)

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    python_startup:

    • 2.7: 7.74 ms +- 0.28 ms
    • 3.4: 18.7 ms +- 0.4 ms
    • 3.5: 20.3 ms +- 0.7 ms
    • 3.6: 26.9 ms +- 0.6 ms (rev c4319c0d0131, before the revert)
    • 3.7: 26.6 ms +- 0.5 ms (rev 36af3566b67a, before the revert)
    • 3.7: 24.6 ms +- 0.0 ms (rev cf7711887b4a, after the revert)

    @gvanrossum
    Copy link
    Member

    So what does that benchmark measure? For me, python 3.6 startup is 44 ms
    and python 2.7 startup is 78 ms (real time; user time is proportionally
    less).

    On Mon, Nov 7, 2016 at 5:40 PM, STINNER Victor <report@bugs.python.org>
    wrote:

    STINNER Victor added the comment:

    python_startup:

    • 2.7: 7.74 ms +- 0.28 ms
    • 3.4: 18.7 ms +- 0.4 ms
    • 3.5: 20.3 ms +- 0.7 ms
    • 3.6: 26.9 ms +- 0.6 ms (rev c4319c0d0131, before the revert)
    • 3.7: 26.6 ms +- 0.5 ms (rev 36af3566b67a, before the revert)
    • 3.7: 24.6 ms +- 0.0 ms (rev cf7711887b4a, after the revert)

    ----------


    Python tracker <report@bugs.python.org>
    <http://bugs.python.org/issue28637\>


    @wm75
    Copy link
    Mannequin

    wm75 mannequin commented Nov 8, 2016

    STINNER Victor added the comment:

    BUT when Python is started from a virtual environment (created by the
    "venv" module), the re module is important by default.

    haypo@speed-python$ venv/bin/python3 -c 'import sys; print("re" in sys.modules)'
    True

    Exciting, I just verified that this is true and running python3 from a venv really seems to be the only situation, in which the re module gets imported during startup (at least it's only this one branch in site.py that uses it).

    If adding a single enum import to re causes such a big startup time difference I wonder how much more could be gained for the venv case by not importing re at all!

    Turns out that the complete code block in site.py that is used by venvs and that was partially shown by @Haypo is:

    CONFIG_LINE = r'^(?P<key>(\w|[-_])+)\s*=\s*(?P<value>.*)\s*$'
    
    def venv(known_paths):
        global PREFIXES, ENABLE_USER_SITE
    
        env = os.environ
        if sys.platform == 'darwin' and '__PYVENV_LAUNCHER__' in env:
            executable = os.environ['__PYVENV_LAUNCHER__']
        else:
            executable = sys.executable
        exe_dir, _ = os.path.split(os.path.abspath(executable))
        site_prefix = os.path.dirname(exe_dir)
        sys._home = None
        conf_basename = 'pyvenv.cfg'
        candidate_confs = [
            conffile for conffile in (
                os.path.join(exe_dir, conf_basename),
                os.path.join(site_prefix, conf_basename)
                )
            if os.path.isfile(conffile)
            ]
    
        if candidate_confs:
            import re
            config_line = re.compile(CONFIG_LINE)
            virtual_conf = candidate_confs[0]
            system_site = "true"
            # Issue 25185: Use UTF-8, as that's what the venv module uses when
            # writing the file.
            with open(virtual_conf, encoding='utf-8') as f:
                for line in f:
                    line = line.strip()
                    m = config_line.match(line)
                    if m:
                        d = m.groupdict()
                        key, value = d['key'].lower(), d['value']
                        if key == 'include-system-site-packages':
                            system_site = value.lower()
                        elif key == 'home':
                            sys._home = value
    
            sys.prefix = sys.exec_prefix = site_prefix
    
            # Doing this here ensures venv takes precedence over user-site
            addsitepackages(known_paths, [sys.prefix])
    
            # addsitepackages will process site_prefix again if its in PREFIXES,
            # but that's ok; known_paths will prevent anything being added twice
            if system_site == "true":
                PREFIXES.insert(0, sys.prefix)
            else:
                PREFIXES = [sys.prefix]
                ENABLE_USER_SITE = False
    
        return known_paths

    So all the re module is good for here is to parse simple config file records with key/value pairs separated by '='. ´Shouldn't it be straightforward to implement that logic right inside that block directly without requiring a giant import?

    This should easily be doable for 3.6 still, seems as if it would solve the whole issue and probably speed up the performance tests much more than any reverted changesets could.

    What do you think?

    @serhiy-storchaka
    Copy link
    Member

    Proposed patch removes the use of re from site.py.

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    site-not-use-re.patch: The change on site.py LGTM. I don't see why re was used in the first place for such simple text format ;-) I suggest to push the fix into Python 3.6 and 3.7.

    But what is the change in Lib/collections/init.py?

    @serhiy-storchaka
    Copy link
    Member

    Oh, please ignore it. This is a sample code from other issue (bpo-28638).

    @wm75
    Copy link
    Mannequin

    wm75 mannequin commented Nov 8, 2016

    @serhiy.storchaka you've beaten me by a few minutes (still waiting for the test suite to finish). Your patch is "contaminated" by an additional change in collections/init.py though so I'm still uploading my version (which also tries to stick as close as possible to the existing behaviour though that probably won't matter much)

    @serhiy-storchaka
    Copy link
    Member

    It seems to me that current regular expression is not correct. It can keep trailing whitespaces it a value.

    I'm not experienced with venv and don't know what tests are needed.

    @terryjreedy
    Copy link
    Member

    The effect is limited to venv only in a narrow sense. The startup time for running programs from an IDLE editor is also affected. Many other programs also import re either directly or indirectly on startup. For instance, importing argparse imports re. Running Python from Command Prompt:

    Python 3.6.0b3 (default, Nov  1 2016, 03:21:01) [MSC v.1900 64 bit (AMD64)] on win32
    Type "help", "copyright", "credits" or "license" for more information.
    >>> import sys; 're' in sys.modules
    False
    >>> import argparse
    >>> import sys; 're' in sys.modules
    True

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Nov 8, 2016

    New changeset a822818ec74e by Serhiy Storchaka in branch '3.6':
    Issue bpo-28637: No longer use re in site.py.
    https://hg.python.org/cpython/rev/a822818ec74e

    New changeset a4ea837a7f84 by Serhiy Storchaka in branch 'default':
    Issue bpo-28637: No longer use re in site.py.
    https://hg.python.org/cpython/rev/a4ea837a7f84

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    Cool, thanks Serhiy for the site enhancement :-)

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 8, 2016

    Guido: "So what does that benchmark measure? For me, python 3.6 startup is 44 ms and python 2.7 startup is 78 ms (real time; user time is proportionally less)."

    It measures something like "time python -c pass".

    The performance module creates a virtual environment to run benchmarks to get reproductible timings. If you benchmark the Python startup time using your system Python, the timing depends on the number of installed .pth files.

    The code of python_startup benchmark:
    https://github.com/python/performance/blob/master/performance/benchmarks/bm_python_startup.py

    Note: I didn't write the benchmark, it comes from the old benchmark suite.

    @ethanfurman
    Copy link
    Member

    Does this mean we can put enum back in re?

    @ethanfurman ethanfurman changed the title Python startup performance regression Python startup performance regression due to enum in re Nov 8, 2016
    @gvanrossum
    Copy link
    Member

    OK. I believe we also found that the extra slowdown is only in a virtualenv
    so that may explain that I saw something different.

    @gvanrossum gvanrossum changed the title Python startup performance regression due to enum in re Python startup performance regression Nov 9, 2016
    @gpshead
    Copy link
    Member

    gpshead commented Nov 9, 2016

    re: Ethan's question - I think the enum use should be restored in re.

    I realize bpo-28082 (yay palindrome number) is not an urgent change but we created IntEnum for the purpose of more identifiable integer constants.

    So a microbenchmark of "import re" slows down. so what? I don't find this to be a big deal. Other standard library modules also use enum and I expect more to do so in the future. In realistic size programs other things use enum as well so there isn't a hit.

    PS thanks for the site.py improvements!

    @serhiy-storchaka
    Copy link
    Member

    On my computer:

    Importing empty module: 160 us
    Creating empty class: 30 us
    Creating empty function: 0.16 us
    Creating empty Enum/IntEnum: 125/150 us
    Creating Enum/IntEnum member: 25/27 us
    Creating empty namedtuple: 600 us
    Creating namedtuple member: 50 us
    Importing the itertools module: 40 us
    Importing the io module: 900 us
    Importing the os module: 1600 us
    Importing the functools module: 2100 us
    Importing the re module (with all sre submodules): 3300 us
    Python startup time: 43000 us

    @vstinner
    Copy link
    Member Author

    vstinner commented Nov 9, 2016

    About the re module, there is still a regression on the performance of
    the import time: see my msg280271.

    We may also revert the changeset 88110cfbf4dc (issue bpo-28193) if we
    want to keep "import re" as fast as Python 3.5.

    The question is if we consider that the re module is part of the
    Python core modules which must be blasing fast to import.

    @gvanrossum
    Copy link
    Member

    Honestly now the basic startup time is under control I am fine with
    restoring the re enum. We can optimize that later.

    --Guido (mobile)

    @vstinner
    Copy link
    Member Author

    Oh nice, python_startup benchmark at Nov 10 (rev at 8ebaa546a033) is now faster than python_startup at Feb 29 (rev dfeadfb4c8cc): new 16.8 ms, old 19.5. And it's much before when I opened the issue: 26.6 ms. Thanks.

    https://speed.python.org/timeline/#/?exe=4&ben=python_startup&env=1&revs=50&equid=off&quarts=on&extr=on

    The main difference is the removal of "import re" from Lib/site.py. If I added back "import re", python_startup comes back to 24.2 ms +- 0.0 ms. I understand that "import re" adds 7.4 ms. Any additional import has an important cost of python startup performance :-/

    @ethanfurman
    Copy link
    Member

    Leaving re out of site.py is fine; the current question is whether to add enum back to re.

    @gvanrossum
    Copy link
    Member

    I think it's okay to add enum back into re.

    @rhettinger
    Copy link
    Contributor

    Serhiy, thanks for your work. By isolating the few easily rewritten lines in site.py, you saved us from endless contortions trying to avoid using our own batteries.

    @serhiy-storchaka
    Copy link
    Member

    Thanks to Wolfgang. This is his idea, I just faster wrote the patch.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Nov 14, 2016

    New changeset 5fd69d4a93e0 by Victor Stinner in branch '3.6':
    Issue bpo-28637: Reapply changeset 223731925d06
    https://hg.python.org/cpython/rev/5fd69d4a93e0

    @vstinner
    Copy link
    Member Author

    Ethan Furman: "Does this mean we can put enum back in re?"

    I checked manually: adding "import enum" to Lib/re.py has no more impact on "python_startup" benchmark.

    Guido van Rossum: "Honestly now the basic startup time is under control I am fine with restoring the re enum. We can optimize that later."

    I concur with Guido, so I reapplied Ethan's changeset. Enjoy readable str() on re flags ;-)

    @vstinner
    Copy link
    Member Author

    The initial bug (performance regression in python_startup) is fixed. Thanks everyone for the nice discussion. I close the issue.

    Please open new issues if you want to continue efforts on making CPython faster ;-)

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.7 (EOL) end of life performance Performance or resource usage release-blocker
    Projects
    None yet
    Development

    No branches or pull requests

    8 participants