Performance of coverage.py under 3.11

[markshannon]

We* are concerned about what 3.11 is doing to the performance of coverage.py.

This is more of a CPython issue, but I'm hoping that the coverage.py folks can provide some meaningful data about performance.

CPython issue: https://bugs.python.org/issue45923

* @markshannon and @pablogsal

[nedbat]

Can you say more about why you are concerned? Has something slowed down? What is it you would like me to do?

[pablogsal]

Can you say more about why you are concerned? Has something slowed down? What is it you would like me to do?

Check python/cpython#29729 (comment) for instance

[markshannon]

What is it you would like me to do?

Nothing for now, but thanks for the offer.

[cdce8p]

I'm seeing major performance regression with coverage and Python 3.11.0b1 (compared to 3.10).
Tests run on MacOS with coverage 6.3.3.

Project 1 - mostly unit tests

Python version	Time	With Coverage
3.10.4	61s	109s
3.11.0b1	44s (-28%)	171s (+157%)

Project 2 - mostly functional tests

Python version	Time	With Coverage
3.10.4	101s	151s
3.11.0b1	90s (-11%)	800s (+529%) 316s (+209%)

For P1 I also have a CI run on ubuntu with an even bigger difference. Without 24s, with coverage: 391s. (3.11.0b1)

Edit: Some test environments had 6.3.2 installed in which the CTracer was unavailable. Updated run times.

[nedbat]

@cdce8p The most likely cause of a slowdown that large is using the Python tracer instead of the CTracer. Can you add COVERAGE_DEBUG=sys into the environment variables when you run coverage and show the output you get?

[cdce8p]

@cdce8p The most likely cause of a slowdown that large is using the Python tracer instead of the CTracer. Can you add COVERAGE_DEBUG=sys into the environment variables when you run coverage and show the output you get?

Thanks for the quick reply! I checked all environments and it looks like some were still using 6.3.2, not 6.3.3 and thus the CTracer was unavailable. In particular the two outliers. I will include the debug logs from the CI runner below if you still want to take a look.

The times are much better now, however that doesn't resolve all issues. For the mostly unit test suit, I'm still seeing a ~34% (94s -> 126s) slowdown. Whereas the functional tests now need 316s (from 151s), so around ~2x the time of 3.10.4.

> Debug log (old) - with 6.3.2

-- sys -------------------------------------------------------
               coverage_version: 6.3.2
                coverage_module: /home/runner/work/astroid/astroid/venv/lib/python3.11/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: /home/runner/work/astroid/astroid/.coveragerc
                    config_file: /home/runner/work/astroid/astroid/.coveragerc
                config_contents: b'[paths]\nsource =\n   astroid\n\n[report]\ninclude =\n    astroid/*\nomit =\n    */tests/*\nexclude_lines =\n    # Re-enable default pragma\n    pragma: no cover\n\n    # Debug-only code\n    def __repr__\n\n    # Type checking code not executed during pytest runs\n    if TYPE_CHECKING:\n    @overload\n'
                      data_file: -none-
                         python: 3.11.0b1 (main, May  8 2022, 15:20:32) [GCC 9.4.0]
                       platform: Linux-5.13.0-1022-azure-x86_64-with-glibc2.31
                 implementation: CPython
                     executable: /home/runner/work/astroid/astroid/venv/bin/python
                   def_encoding: utf-8
                    fs_encoding: utf-8
                            pid: 1655
                            cwd: /home/runner/work/astroid/astroid
                           path: /home/runner/work/astroid/astroid/venv/bin
                                 /opt/hostedtoolcache/Python/3.11.0-beta.1/x64/lib/python311.zip
                                 /opt/hostedtoolcache/Python/3.11.0-beta.1/x64/lib/python3.11
                                 /opt/hostedtoolcache/Python/3.11.0-beta.1/x64/lib/python3.11/lib-dynload
                                 /home/runner/work/astroid/astroid/venv/lib/python3.11/site-packages
                                 /home/runner/work/astroid/astroid
                    environment: DEFAULT_PYTHON = 3.8
                                 HOME = /home/runner
                   command_line: /home/runner/work/astroid/astroid/venv/bin/coverage debug sys
                sqlite3_version: 2.6.0
         sqlite3_sqlite_version: 3.31.1
             sqlite3_temp_store: 0
        sqlite3_compile_options: COMPILER=gcc-9.4.0; ENABLE_COLUMN_METADATA; ENABLE_DBSTAT_VTAB
                                 ENABLE_FTS3; ENABLE_FTS3_PARENTHESIS; ENABLE_FTS3_TOKENIZER
                                 ENABLE_FTS4; ENABLE_FTS5; ENABLE_JSON1
                                 ENABLE_LOAD_EXTENSION; ENABLE_PREUPDATE_HOOK; ENABLE_RTREE
                                 ENABLE_SESSION; ENABLE_STMTVTAB; ENABLE_UNLOCK_NOTIFY
                                 ENABLE_UPDATE_DELETE_LIMIT; HAVE_ISNAN; LIKE_DOESNT_MATCH_BLOBS
                                 MAX_SCHEMA_RETRY=25; MAX_VARIABLE_NUMBER=250000; OMIT_LOOKASIDE
                                 SECURE_DELETE; SOUNDEX; TEMP_STORE=1
                                 THREADSAFE=1; USE_URI

> Debug log (new) - with 6.3.3

-- sys -------------------------------------------------------
               coverage_version: 6.3.3
                coverage_module: /home/runner/work/astroid/astroid/venv/lib/python3.11/site-packages/coverage/__init__.py
                         tracer: -none-
                        CTracer: available
           plugins.file_tracers: -none-
            plugins.configurers: -none-
      plugins.context_switchers: -none-
              configs_attempted: .coveragerc
                   configs_read: /home/runner/work/astroid/astroid/.coveragerc
                    config_file: /home/runner/work/astroid/astroid/.coveragerc
                config_contents: b'[paths]\nsource =\n   astroid\n\n[report]\ninclude =\n    astroid/*\nomit =\n    */tests/*\nexclude_lines =\n    # Re-enable default pragma\n    pragma: no cover\n\n    # Debug-only code\n    def __repr__\n\n    # Type checking code not executed during pytest runs\n    if TYPE_CHECKING:\n    @overload\n'
                      data_file: -none-
                         python: 3.11.0b1 (main, May  8 2022, 15:20:32) [GCC 9.4.0]
                       platform: Linux-5.13.0-1022-azure-x86_64-with-glibc2.31
                 implementation: CPython
                     executable: /home/runner/work/astroid/astroid/venv/bin/python
                   def_encoding: utf-8
                    fs_encoding: utf-8
                            pid: 1737
                            cwd: /home/runner/work/astroid/astroid
                           path: /home/runner/work/astroid/astroid/venv/bin
                                 /opt/hostedtoolcache/Python/3.11.0-beta.1/x64/lib/python311.zip
                                 /opt/hostedtoolcache/Python/3.11.0-beta.1/x64/lib/python3.11
                                 /opt/hostedtoolcache/Python/3.11.0-beta.1/x64/lib/python3.11/lib-dynload
                                 /home/runner/work/astroid/astroid/venv/lib/python3.11/site-packages
                                 /home/runner/work/astroid/astroid
                    environment: DEFAULT_PYTHON = 3.8
                                 HOME = /home/runner
                   command_line: /home/runner/work/astroid/astroid/venv/bin/coverage debug sys
                sqlite3_version: 2.6.0
         sqlite3_sqlite_version: 3.31.1
             sqlite3_temp_store: 0
        sqlite3_compile_options: COMPILER=gcc-9.4.0; ENABLE_COLUMN_METADATA; ENABLE_DBSTAT_VTAB
                                 ENABLE_FTS3; ENABLE_FTS3_PARENTHESIS; ENABLE_FTS3_TOKENIZER
                                 ENABLE_FTS4; ENABLE_FTS5; ENABLE_JSON1
                                 ENABLE_LOAD_EXTENSION; ENABLE_PREUPDATE_HOOK; ENABLE_RTREE
                                 ENABLE_SESSION; ENABLE_STMTVTAB; ENABLE_UNLOCK_NOTIFY
                                 ENABLE_UPDATE_DELETE_LIMIT; HAVE_ISNAN; LIKE_DOESNT_MATCH_BLOBS
                                 MAX_SCHEMA_RETRY=25; MAX_VARIABLE_NUMBER=250000; OMIT_LOOKASIDE
                                 SECURE_DELETE; SOUNDEX; TEMP_STORE=1
                                 THREADSAFE=1; USE_URI
============================= test session starts ==============================

[nedbat]

@markshannon @pablogsal I am also seeing a problem with coverage.py being 2x slower on 3.11 than on 3.10:

Median for bug1339.py, python3.10, cov=none: 0.180s
Median for bug1339.py, python3.10, cov=6.4.1: 0.421s
Median for bug1339.py, python3.11, cov=none: 0.141s
Median for bug1339.py, python3.11, cov=6.4.1: 0.835s
Median for bm_sudoku.py, python3.10, cov=none: 10.946s
Median for bm_sudoku.py, python3.10, cov=6.4.1: 28.293s
Median for bm_sudoku.py, python3.11, cov=none: 10.215s
Median for bm_sudoku.py, python3.11, cov=6.4.1: 60.590s
Median for bm_spectral_norm.py, python3.10, cov=none: 14.882s
Median for bm_spectral_norm.py, python3.10, cov=6.4.1: 37.359s
Median for bm_spectral_norm.py, python3.11, cov=none: 10.415s
Median for bm_spectral_norm.py, python3.11, cov=6.4.1: 76.129s

[pablogsal]

Can you provide a reproducer that we can play with, as possible with the minimum set of dependencies possible?

[nedbat]

Here are the same numbers in a more comprehensible form:

Coverage	file	3.10	3.11	3.11 vs 3.10
none	bug1339.py	0.180 s	0.141 s	78%
none	bm_sudoku.py	10.946 s	10.215 s	93%
none	bm_spectral_norm.py	14.882 s	10.415 s	70%
6.4.1	bug1339.py	0.421 s	0.835 s	198%
6.4.1	bm_sudoku.py	28.293 s	60.590 s	214%
6.4.1	bm_spectral_norm.py	37.359 s	76.129 s	204%