Performance is poor on M1 silicon

[stevenrhall]

Describe the bug
For my project, the overhead of running coverage is about 10% on my 2017 Macbook Pro (Intel i7), but a whopping 250% on my 2021 MacBook Pro (M1 Max), so that in fact running coverage run -m pytest on the M1 is more than 50% slower on the Intel i7.

Some more details: I ran a matrix 6 cases to illustrate the issue. The three machines are the Intel i7, M1 (native arm64), and M1 (Rosetta i386). For each machine, I run my test suite with the command

$ time pytest

or

$ time coverage run -m pytest

The resulting run times are summarized in the table below:

+-------------------------------+--------------------------------+-----------------------------+
|                               |    MacBook Pro (Apple M1 Max)  |                             |
|                               +----------------+---------------+ 2017 Macbook Pro (Intel i7) |
|                               | Native (arm64) | Rosetta (x86) |                             |
+-------------------------------+----------------+---------------+-----------------------------+
| $ time pytest                 |      67.37     |     109.37    |          139.37             |
| $ time coverage run -m pytest |     236.45     |     125.03    |          153.01             |
+-------------------------------+--------------------------------+-----------------------------+
| Overhead                      |      251%      |      14.3%    |           9.8%              |
+-------------------------------+--------------------------------+-----------------------------+

The take away is that the performance of coverage (at least on my project) is so poor on the native arm36 architecture that it's much faster to run it using i386 binaries and Rosetta, or even run it on the old Intel i7 machine. The performance is so poor that there must be an issue related to either the arm64 architecture (or rather binaries compiled to arm64), or perhaps a specific issue with one of the packages I'm using. Note that pytest itself runs fine --- it's only when run using coverage that there is an issue.

It may take a bit of work on both my part to get you code that you can use to reproduce. I'll answer all the questions I can, and if you need me to I will fork my project to give a minimal use case.

What version of Python are you using?

3.9.9 (using Homebrew and pyenv).

What version of coverage.py shows the problem?

6.2

What versions of what packages do you have installed?

attrs--21.2.0
casadi--3.5.5.post2
coverage--6.2
cycler--0.11.0
cyipopt--1.1.0
Cython--0.29.24
fonttools--4.28.2
iniconfig--1.1.1
jsonschema--4.2.1
kiwisolver--1.3.2
matplotlib--3.5.0
numpy--1.21.4
packaging--21.3
Pillow--8.4.0
pluggy--1.0.0
py--1.11.0
pyparsing--3.0.6
pyrsistent--0.18.0
pytest--6.2.5
python-dateutil--2.8.2
scipy--1.7.3
setuptools-scm--6.3.2
six--1.16.0
toml--0.10.2
tomli--1.2.2

What code are you running?

See my comment above. I can provide a minimal example if needed, but would probably have to excise all the casadi features so that you don't have to compile casadi yourself (which is the only option for native M1 right now).

What commands did you run?

$ time pytest
$ time coverage run -m pytest

Expected behavior

I expected that using the coverage command would add some overhead to running pytest, perhaps around 10%. Instead, using M1 native binaries, I got an additional 250% overhead.

Additional context

None.

[nedbat]

What is the output of coverage debug sys for you on the M1?

[stevenrhall]

Here's the output for coverage debug sys:

-- sys -------------------------------------------------------
               coverage_version: 6.2
                coverage_module: /Users/steve/.pyenv/versions/3.9.9/lib/python3.9/site-packages/coverage/__init__.py
                         tracer: -none-
                        CTracer: unavailable
           plugins.file_tracers: -none-
            plugins.configurers: -none-
      plugins.context_switchers: -none-
              configs_attempted: .coveragerc
                   configs_read: /Users/steve/Dropbox/YAPSS/YAPSS/.coveragerc
                    config_file: /Users/steve/Dropbox/YAPSS/YAPSS/.coverager
                config_contents: b'[run]\nsource =\n    src/yapss/\nomit =\n    */site-packages/*\nbranch = True\n\n[report]\nexclude_lines =\n    pragma: no cover\n    def __repr__\n    if self.debug:\n    if settings.DEBUG\n    raise AssertionError\n    raise RuntimeError\n    if TYPE_CHECKING:\n    raise NotImplementedError\n    if 0:\n    if __name__ == .__main__.:\n'
                      data_file: -none-
                         python: 3.9.9 (main, Nov 30 2021, 10:15:14) [Clang 13.0.0 (clang-1300.0.29.3)]
                       platform: macOS-12.0.1-arm64-arm-64bit
                 implementation: CPython
                     executable: /Users/steve/.pyenv/versions/3.9.9/bin/python3.9
                   def_encoding: utf-8
                    fs_encoding: utf-8
                            pid: 76823
                            cwd: /Users/steve/Dropbox/YAPSS/YAPSS
                           path: /Users/steve/.pyenv/versions/3.9.9/bin
                                 /Users/steve/.pyenv/versions/3.9.9/lib/python39.zip
                                 /Users/steve/.pyenv/versions/3.9.9/lib/python3.9
                                 /Users/steve/.pyenv/versions/3.9.9/lib/python3.9/lib-dynload
                                 /Users/steve/.pyenv/versions/3.9.9/lib/python3.9/site-packages
                                 /Users/steve/Dropbox/YAPSS/YAPSS/src
                    environment: HOME = /Users/steve
                                 PYENV_DIR = /Users/steve/Dropbox/YAPSS/YAPSS
                                 PYENV_HOOK_PATH = /Users/steve/.pyenv/pyenv.d:/opt/homebrew/Cellar/pyenv/2.2.2/pyenv.d:/opt/homebrew/etc/pyenv.d:/etc/pyenv.d:/usr/lib/pyenv/hooks
                                 PYENV_ROOT = /Users/steve/.pyenv
                                 PYENV_SHELL = zsh
                                 PYENV_VERSION = 3.9.9
                                 PYENV_VIRTUALENV_INIT = 1
                   command_line: /Users/steve/.pyenv/versions/3.9.9/bin/coverage debug sys
                sqlite3_version: 2.6.0
         sqlite3_sqlite_version: 3.36.0
             sqlite3_temp_store: 0
        sqlite3_compile_options: BUG_COMPATIBLE_20160819; COMPILER=clang-13.0.0; DEFAULT_CACHE_SIZE=2000
                                 DEFAULT_CKPTFULLFSYNC; DEFAULT_JOURNAL_SIZE_LIMIT=32768; DEFAULT_MEMSTATUS=0
                                 DEFAULT_PAGE_SIZE=4096; DEFAULT_SYNCHRONOUS=2; DEFAULT_WAL_SYNCHRONOUS=1
                                 ENABLE_API_ARMOR; ENABLE_BYTECODE_VTAB; ENABLE_COLUMN_METADATA
                                 ENABLE_DBSTAT_VTAB; ENABLE_FTS3; ENABLE_FTS3_PARENTHESIS
                                 ENABLE_FTS3_TOKENIZER; ENABLE_FTS4; ENABLE_FTS5
                                 ENABLE_JSON1; ENABLE_LOCKING_STYLE=1; ENABLE_NORMALIZE
                                 ENABLE_PREUPDATE_HOOK; ENABLE_RTREE; ENABLE_SESSION
                                 ENABLE_SNAPSHOT; ENABLE_SQLLOG; ENABLE_STMT_SCANSTATUS
                                 ENABLE_UNKNOWN_SQL_FUNCTION; ENABLE_UPDATE_DELETE_LIMIT; HAS_CODEC_RESTRICTED
                                 HAVE_ISNAN; MAX_LENGTH=2147483645; MAX_MMAP_SIZE=1073741824
                                 MAX_VARIABLE_NUMBER=500000; OMIT_AUTORESET; OMIT_LOAD_EXTENSION
                                 STMTJRNL_SPILL=131072; SYSTEM_MALLOC; THREADSAFE=2
                                 USE_URI

The problem is definitely with the casadi package. If I prune my project to eliminate that package, everything works fine. (Well, at least regarding coverage.) For x86 code, I just pip install casadi. For M1 native code, I have to do this:

git clone https://github.com/casadi/casadi.git casadi
cd casadi
git checkout 3.5.5
mkdir build
cd build
cmake -DWITH_PYTHON=ON -DWITH_PYTHON3=ON ..
make
sudo make install

which installs a site package to python. The casadi package then works fine, but somehow it's not excluded (I guess) from coverage, even though all the other site packages appear to be. I've looked at the read the docs pages and can't see what (if anything) I am doing wrong.

[nedbat]

This line in the debug output is the key:

CTracer: unavailable

That means that you are using a Python trace function instead of a C trace function, so of course execution is much slower. I don't know why casadi would make that happen. Can you run coverage debug sys again without casadi to see if the CTracer is then available?

[stevenrhall]

Can you run coverage debug sys again without casadi to see if the CTracer is then available?

It is still not available.

OK, I think we're on the right track here! I removed casadi from my minimal project and the problem persists (CTracer still not available). That's confirmed by checking the version:

$ coverage --version

Coverage.py, version 6.2 without C extension
Full documentation is at https://coverage.readthedocs.io

If using the native M1 python (Homebrew), I launch python 3.9.9 I get this:

>>> from coverage.tracer import CTracer
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ImportError: dlopen(/Users/steve/.pyenv/versions/3.9.9/lib/python3.9/site-packages/coverage/tracer.cpython-39-darwin.so, 0x0002): tried: '/Users/steve/.pyenv/versions/3.9.9/lib/python3.9/site-packages/coverage/tracer.cpython-39-darwin.so' (mach-o file, but is an incompatible architecture (have 'x86_64', need 'arm64e')), '/usr/local/lib/tracer.cpython-39-darwin.so' (no such file), '/usr/lib/tracer.cpython-39-darwin.so' (no such file)

Checking the shared library file directory directly gives:

$ file /Users/steve/.pyenv/versions/3.9.9/lib/python3.9/site-packages/coverage/tracer.cpython-39-darwin.so
/Users/steve/.pyenv/versions/3.9.9/lib/python3.9/site-packages/coverage/tracer.cpython-39-darwin.so: Mach-O 64-bit bundle x86_64

The wheel file for the M1 architecture should include an arm64 bundle rather than an x86_64 bundle, shouldn't it?

[stevenrhall]

(Edited to give simpler workaround.) OK, cloning the package and doing a pip install correctly builds an arm64 version of coverage. Now $ coverage run - m pytest runs in 76.74 seconds, where $ pytest runs in 67.14 seconds, a 14% overhead, about what I would expect.

So it does look like the problem is with the pypi wheel for OSX, I think?

[nedbat]

I'm afraid I'm a bit in the dark about what goes into the wheels. I added "arm64" to the Mac wheels in this run: https://github.com/nedbat/coveragepy/actions/runs/1527750491 Here is the 3.9 wheel, can you try it? https://www.dropbox.com/s/uqvme4gbwcikfnm/coverage-6.2.1a0-cp39-cp39-macosx_11_0_arm64.whl?dl=1

[stevenrhall]

That works!

I was in the dark about wheels, too, but it turns out that to install you just do

$ pip install coverage-6.2.1a0-cp39-cp39-macosx_11_0_arm64.whl

to install if you're working with a local copy.

Thanks so much.

[nedbat]

Thanks for the confirmation. This is fixed in commit 157053d

[nedbat]

This is now released as part of coverage 6.3.