8000 MyPy 0.750 slow startup (or hang) on macOS · Issue #8055 · python/mypy · GitHub
[go: up one dir, main page]

Skip to content

MyPy 0.750 slow startup (or hang) on macOS #8055

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

Open
nickwilliams-eventbrite opened this issue Dec 2, 2019 · 24 comments
Open

MyPy 0.750 slow startup (or hang) on macOS #8055

nickwilliams-eventbrite opened this issue Dec 2, 2019 · 24 comments
Labels
bug mypy got something wrong performance

Comments

@nickwilliams-eventbrite
Copy link
  • Are you reporting a bug, or opening a feature request?
    Bug report

  • Please insert below the code you are checking with mypy,
    or a mock-up repro if the source is private. We would appreciate
    if you try to simplify your case to a minimal repro.
    This is not applicable to this bug report.

  • What is the actual behavior/output?
    Running the mypy . command hangs forever after upgrading to MyPy 0.750 on macOS. Even trying mypy --version to verify the installed version hangs forever. Both commands have to be killed with Ctrl+C (pressing that multiple times is required, actually) after several minutes of waiting for output. Also tried uninstalling and re-installing MyPy from scratch with no luck. Only downgrading to 0.740 solves it from hanging forever, but now mypy --version takes about 45 seconds instead of < 1 second like it was before upgrading and downgrading, even though it outputs 0.740. Here is example output of killing mypy --version under 0.750 after several minutes:

    $ mypy --version
    ^C^C^C^C^C^C^C^C^CTraceback (most recent call last):
      File "/Users/nwilliams/.virtualenvs/pysoa3/bin/mypy", line 6, in <module>
        from mypy.__main__ import console_entry
      File "/Users/nwilliams/.virtualenvs/pysoa3/lib/python3.7/site-packages/mypy/__main__.py", line 4, in <module>
        from mypy.main import main
      File "mypy/main.py", line 13, in <module>
      File "mypy/build.py", line 33, in <module>
      File "mypy/semanal.py", line 95, in <module>
      File "mypy/typeanal.py", line 30, in <module>
      File "<frozen importlib._bootstrap>", line 978, in _find_and_load
    KeyboardInterrupt
    
  • What is the behavior/output you expect?
    For mypy . to run in generally the same amount of time it took previously (~10-15 seconds) and for mypy --version to output and exit instantly, instead of hanging forever like they now do.

  • What are the versions of mypy and Python you are using?

    $ python --version
    Python 3.7.4
    $ cat ~/.virtualenvs/pysoa3/lib/python3.7/site-packages/mypy/version.py 
    __version__ = "0.750"
    

    The Python version was installed from Homebrew.
    Do you see the same issue after installing mypy from Git master?
    If I pip install git+https://github.com/python/mypy.git@v0.750, mypy . works. That's the same version (0.750), just installed from Git instead of PyPi. So this appears to be an issue with the PyPi wheel.

  • What are the mypy flags you are using? (For example --strict-optional)

    [mypy]
    python_version = 3.7
    check_untyped_defs = True
    [mypy-tasks]
    ignore_errors = True
    [mypy-(several projects listed here).*]
    ignore_missing_imports = True
    ...
    
@emmatyping
Copy link
Member

Can you try installing mypy with the pip flag --no-binary=mypy, so that it uses a source release? My guess is mypyc may be causing issues.

@nickwilliams-eventbrite
8000
Copy link
Author

pip install mypy==0.750 --no-binary=mypy installed from the source tarball and it appears to work. Both mypy . and mypy --version complete without hanging forever, but mypy --version still takes about 30-45 seconds instead of the usual < 1 second.

In a different virtualenv where I still have MyPy 0.740 installed and never tried to upgrade it, mypy --version takes < 1 second still. So I tried pip install mypy==0.750 --no-binary=mypy in that virtualenv as well, and now mypy --version completes but takes 30-45 seconds.

@nickwilliams-eventbrite
Copy link
Author
nickwilliams-eventbrite commented Dec 2, 2019

I should be really clear about something, too: This problem appears to be limited to macOS. On both an Ubuntu machine and an Ubuntu Docker container running on my Mac, 0.750 does not exhibit these symptoms.

@emmatyping
Copy link
Member

Hm, okay that is rather odd. Can you please try python -m mypy --version? I'm trying to eliminate that it is the startup script going wrong.

@emmatyping emmatyping added bug mypy got something wrong priority-0-high labels Dec 2, 2019
@nickwilliams-eventbrite
Copy link
Author

Whoa. python -m mypy --version is waaayyyy faster. < 1 second.

@emmatyping
Copy link
Member

Fascinating! My guess is that there is something going on with the startup script that setuptools installs. Can you run python -c 'import pkg_resources' and see how long that takes? Also if you want to debug this in real time, I'll be watching https://gitter.im/python/typing and we can debug via live chat.

@JukkaL
Copy link
Collaborator
JukkaL commented Dec 3, 2019

I can reproduce this on macOS. However, it seems that this only affects the first run:

$ pip install mypy
Collecting mypy
  Using cached https://files.pythonhosted.org/packages/e6/98/4f2acce4aea2ecb01bf5ac80f64a9c56b00373e0887447422343d93bc034/mypy-0.750-cp35-cp35m-macosx_10_6_x86_64.whl
Processing /Users/jukka/Library/Caches/pip/wheels/ee/62/05/814eedac709dcbcfb1ff3aae918ed67f7140314b77e420bb5e/typed_ast-1.4.0-cp35-cp35m-macosx_10_6_intel.whl
Collecting typing-extensions>=3.7.4
  Using cached https://files.pythonhosted.org/packages/03/92/705fe8aca27678e01bbdd7738173b8e7df0088a2202c80352f664630d638/typing_extensions-3.7.4.1-py3-none-any.whl
Collecting mypy-extensions<0.5.0,>=0.4.0
  Using cached https://files.pythonhosted.org/packages/5c/eb/975c7c080f3223a5cdaff09612f3a5221e4ba534f7039db34c35d95fa6a5/mypy_extensions-0.4.3-py2.py3-none-any.whl
Installing collected packages: typed-ast, typing-extensions, mypy-extensions, mypy
Successfully installed mypy-0.750 mypy-extensions-0.4.3 typed-ast-1.4.0 typing-extensions-3.7.4.1
$ time mypy --version
mypy 0.750

real	0m21.926s
user	0m0.176s
sys	0m0.085s
$ time mypy --version
mypy 0.750

real	0m0.321s
user	0m0.157s
sys	0m0.058s
$ time mypy --version
mypy 0.750

real	0m0.197s
user	0m0.129s
sys	0m0.040s

I can also reproduce the issue on older mypy versions, all the way back to 0.700, so it seems that this may be caused by the environment. Using python -m mypy doesn't make any difference in my case (the first run is slow, the second fast).

I'll continue investigating this.

@nickwilliams-eventbrite Can you verify if this only affects the first run after installation (as seems to be the case for me), and if this also happens with mypy 0.700?

@TH3CHARLie
Copy link
Collaborator
TH3CHARLie commented Dec 3, 2019

I verifed on my MacOS machine that the first run is slow and later ones are OK.(From 0.750 back to 0.700, 0.670 is OK) @JukkaL

@JukkaL
Copy link
Collaborator
JukkaL commented Dec 3, 2019

@TH3CHARLie Thanksk for the information!

I think I figured out what triggers the behavior on my Mac: the first run is consistently slow if I have Cisco AnyConnect (VPN) running. Here's the behavior I'm observing (I've repeated this a few times, so it probably isn't random):

  1. If AnyConnect is not running, the runtime after installation is consistently below 10s, typically around 4s.
  2. Once AnyConnect is running, the runtime is usually at least 14s.
  3. After I close AnyConnect, the runtime is still slow after the first subsequent installation, but goes below 10s after subsequent installations (typically around 4s).

I still don't undertand why AnyConnect might be causing this. Perhaps something does a network request when starting mypy? I'm going to debug further, now that I have a repro.

Can somebody who has experienced the issue try closing all applications (other than your terminal) and see if it helps? Try installing mypy several times, since the first run after closing applications may still be slow.

@TH3CHARLie
Copy link
Collaborator
TH3CHARLie commented Dec 3, 2019

@JukkaL quick repro: closed all applications except terminal, install mypy using pip and after installing, turn on/off Wi-Fi:

mypy 0.740 Wi-Fi On: 34.075 total Off: 1.986 total
mypy 0.750 Wi-Fi On: 30.693 total Off: 1.971 total

I have no Cisco AnyConnect but the results indicate that the phenomenon is not closely related to any particular software but some general network requests maybe

Some addups: I tried some other packages:pytest and flake8, both of them run slower on the first run when Wi-Fi is on, and run using normal time on the first run when Wi-Fi is off. The statistical comparison is less obvious compares to mypy, though: 0.8s(On) and 0.2s(Off)

@JukkaL
Copy link
Collaborator
JukkaL commented Dec 3, 2019

Based on fs_usage output, this may be related to XProtect, the built-in anti-malware tool in macOS.

Here's an extract from fs_usage output during a slow mypy run:

13:45:59.062790  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000009   python3.7.178431
13:45:59.062821  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000008   python3.7.178431
13:45:59.062829  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000005   python3.7.178431
13:45:59.062855  open              F=3        (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000025   python3.7.178431
13:45:59.062939  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000012   syspolicyd.175955
13:45:59.062963  access                       (R___)    /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000019   syspolicyd.175955
13:45:59.063099  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000007   syspolicyd.175955
13:45:59.063192  getattrlist                            /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000009   syspolicyd.175955
13:45:59.063200  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000005   syspolicyd.175955
13:45:59.063208  statfs64                               /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000005   syspolicyd.175955
13:45:59.063247  getattrlist                            /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000007   syspolicyd.175955
13:45:59.063262  getattrlist                            /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000013   syspolicyd.175955
13:45:59.069590  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000012   syspolicyd.177749
13:45:59.070112  open              F=16       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000017   syspolicyd.177749
13:45:59.070133  open              F=20       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000015   syspolicyd.177749
13:45:59.070422  getattrlist                            /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000061   syspolicyd.177749
13:45:59.070714  open              F=16       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000023   syspolicyd.177749
13:45:59.070778  open              F=22       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000043   syspolicyd.177749
13:45:59.070921  getattrlist                            /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000094   XprotectService.177751
13:45:59.070952  open              F=16       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000017   syspolicyd.177749
13:45:59.071011  open              F=16       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000015   syspolicyd.177749
13:45:59.080986  lstat64                                /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000012   XprotectService.177748
13:45:59.081019  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000005   XprotectService.177748
13:45:59.081049  lstat64                                /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000006   XprotectService.177748
13:45:59.081054  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000004   XprotectService.177748
13:45:59.081063  open              F=3        (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000045   XprotectService.178036
13:45:59.081086  open              F=4        (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000024   XprotectService.177748
13:45:59.081138  open              F=5        (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000040   XprotectService.177748
13:45:59.081221  open              F=5        (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000033   XprotectService.177748
13:45:59.294047  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000012   syspolicyd.177752
13:45:59.294665  open              F=20       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000021   syspolicyd.177752
13:45:59.294687  open              F=22       (R___________)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000016   syspolicyd.177752
13:45:59.295896  open                   [ 20] (R_____N____X)  /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                      0.000014   syspolicyd.177749
13:45:59.295905  stat64                                 /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                            0.000008   syspolicyd.177749
13:45:59.296337  fcntl             F=3   <CMD=98>    /Users/jukka/venv/test/lib/python3.7/site-packages/mypy/semanal_enum.cpython-37m-darwin.so                                                                               0.233475   python3.7.178431

If I'm reading this correctly, most of the time is spent in XProtect. Looking at the output more generally, it seems that importing modules is slow. There is no particular single thing which takes a lot of time, but many somewhat slow operations (since there are many C extensions).

My current hypothesis is that XProtect sometimes slows things down, but once it's scanned a file once, it no longer has a performance impact. If I'm correct, I'm not sure if there's anything we can do about this. Maybe Apple will fix the issue in a future macOS update.

A simple, partial workaround would be to compile fewer modules, assuming Python modules won't be impacted by this. Some modules aren't performance-sensitive so compiling them isn't very important.

@JukkaL
Copy link
Collaborator
JukkaL commented Dec 3, 2019

My investigation still doesn't shed light on why mypy 0.750 would hang forever. It's possible that there are two separate issues.

@nickwilliams-eventbrite Can you verify that 0.750 actually hangs forever and is not just extremely slow (e.g. run it with python -v -v -m mypy --version and see if there's a trickle of output)?

@JukkaL
Copy link
Collaborator
JukkaL commented Dec 3, 2019

@nickwilliams-eventbrite Actually you'd need to run PYTHONVERBOSE=x mypy --version, I think, if python -m mypy is not hanging. Also I'd like to know if mypy --version is still failing after you've successfully run python -m mypy --version.

@JukkaL
Copy link
Collaborator
JukkaL commented Dec 3, 2019

I have another hypothesis: this problem/these problems on happen on Catalina. If you can reproduce the problem, it would be interesting to hear which version of macOS you are running.

@TH3CHARLie
Copy link
Collaborator

@JukkaL macOS 10.15.1 Catalina

@nielsbom
Copy link

Maybe I can help as well:

I'm on MacOS Catalina 10.15.2
I've installed mypy 0.761 with pip.
I'm using Python 3.7.5.

Running mypy --version the first time gives this traceback:

^CTraceback (most recent call last):
  File "/usr/local/bin/mypy", line 5, in <module>
    from mypy.__main__ import console_entry
  File "/usr/local/lib/python3.7/site-packages/mypy/__main__.py", line 4, in <module>
    from mypy.main import main
  File "mypy/main.py", line 13, in <module>
  File "mypy/build.py", line 34, in <module>
  File "mypy/semanal_main.py", line 39, in <module>
KeyboardInterrupt

Subsequent runs run fast (normal speed I'm assuming).

@JukkaL let me know if you want more debugging runs

@JukkaL JukkaL changed the title MyPy 0.750 hangs forever on macOS MyPy 0.750 slow startup (or hang) on macOS Jun 25, 2020
@JukkaL
Copy link
Collaborator
JukkaL commented Jun 26, 2020

Here's another idea: We currently generate a C extension shim for each compiled module. Maybe the shims could be Python modules instead? This might speed up the initial run on macOS. I created mypyc/mypyc#742 to track this idea.

@JukkaL
Copy link
Collaborator
JukkaL commented Sep 23, 2022

Is anybody still seeing this? This seems to have improved in recent macOS releases. If you encounter this, please leave a comment with the macOS version (and mypy version) you are using.

@ghost
Copy link
ghost commented Sep 29, 2022

Indeed using the newest version speeded up mypy significantly on my side. Many thanks!

@hauntsaninja
Copy link
Collaborator

@JukkaL I still see consistently this with compiled mypy 0.991 and macOS 12.6.1.

Initial run takes like 8-15s, subsequent runs take <1s (everything measured with --no-incremental --cache-dir=/dev/null

@hauntsaninja
Copy link
Collaborator
hauntsaninja commented Nov 28, 2022

Okay, I can't reproduce when running interactively in shell, only when running in a subprocess.

Specifically, something like the following should reproduce:

import sys
python = sys.executable
import subprocess, time
subprocess.run(f"{python} -m pip install --upgrade mypy==0.991 --force-reinstall", shell=True)
start = time.perf_counter()
subprocess.run(f"{python} -m mypy --version", shell=True)
end = time.perf_counter()
print(end - start)

@hauntsaninja
Copy link
Collaborator
hauntsaninja commented Aug 21, 2023

My reproducer still takes about 6.5s with mypy 1.5.1 and macOS 13.5.

I'm not sure we have a path forward, so closing for now.

6D40
@brandonchinn178
Copy link

FYI This is still reproducible for me, macOS 15.5 and mypy 1.15.0

$ rm -rf venv && python3.13 -m venv venv && venv/bin/pip install mypy

$ # first time slow
$ time venv/bin/mypy --version
mypy 1.15.0 (compiled: yes)
venv/bin/mypy --version  0.31s user 0.14s system 4% cpu 10.016 total

$ # subsequent times fast
$ time venv/bin/mypy --version
mypy 1.15.0 (compiled: yes)
venv/bin/mypy --version  0.13s user 0.04s system 85% cpu 0.195 total

After some print-debugging, the from mypy.__main__ import console_entry line in the entrypoint script takes 10 seconds

Running as either PYTHONVERBOSE=x venv/bin/mypy --version or venv/bin/python -vv venv/bin/mypy --version doesn't show any differences in outputs between the slow or fast invocations

I can also repro with venv/bin/python -c 'import mypy.__main__ '. Interestingly, venv/bin/python -c 'import mypy' does not show slowness. Trying out different imports, I see:

  • mypy - 0.4s
  • mypy.main - 10s
  • mypy.build - 10s
  • mypy.semanal_main - 10s
  • mypy.semanal_classprop - 2.5s
  • mypy.semanal_shared - 4.2s
  • mypy.nodes - 1.3s
  • mypy.types - 2s
  • mypy.state - 0.5s
  • mypy.util - 0.5s
  • mypy.git - 0.5s
  • mypy.strconv - 1.2s
  • mypy.options - 1.0s
  • mypy_extensions - 0.03s

I'm not sure why it'd be faster to import these the second time around, as I see __pycache__ populated even before the first run.

@hauntsaninja
Copy link
Collaborator

Yeah still an issue, I guess we should leave the issue open so it's at least more discoverable. But I'm not sure how to work around macOS antivirus

@hauntsaninja hauntsaninja reopened this May 22, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug mypy got something wrong performance
Projects
None yet
Development

No branches or pull requests

8 participants
0