Poor performance in Python 3.12 #1665

asmeurer · 2023-08-04T20:24:46Z

Describe the bug

I recently added a Python 3.12-dev build to a project where I enable coverage on all the CI test runs, and the 3.12 build has consistently been taking nearly twice a long to complete as the 3.8-3.11 builds.

I made a test PR disabling coverage and the issue went away. Obviously without coverage the tests run faster, but the point is that the different Python versions all ran in about the same time.

Compare some builds (with coverage):

https://github.com/Quansight-Labs/ndindex/actions/runs/5734923621/usage?pr=155

https://github.com/Quansight-Labs/ndindex/actions/runs/5734722635/usage

A build with coverage disabled:

https://github.com/Quansight-Labs/ndindex/actions/runs/5765483809/usage?pr=161

To Reproduce

I haven't yet tried to install Python 3.12 to see if I can reproduce this locally, but the performance hit is pretty consistent on CI (you can see it on pretty much every recent build in Quansight-Labs/ndindex#155 for example).

Happy to provide more info, and try to repro locally if you can suggest an easy way to install a Python 3.12 environment. The package in question is pure Python, but the tests depend heavily on both numpy (I've been installing 3.12-compatible dev wheels from https://pypi.anaconda.org/scientific-python-nightly-wheels/simple) and hypothesis.

I mostly just wanted to make sure was on your radar since I didn't see any other issues about it.

nedbat · 2023-08-04T20:37:58Z

The first thing to check is whether 3.12 has the C extension available. coverage --help will show:

% coverage --help
Coverage.py, version 7.2.7 with C extension
Measure, collect, and report on code coverage in Python programs.

or:

% coverage debug sys
-- sys -------------------------------------------------------
               coverage_version: 7.2.7
                coverage_module: /usr/local/virtualenvs/tmp-4637fade7458920/lib/python3.10/site-packages/coverage/__init__.py
                         tracer: -none-
                        CTracer: available

asmeurer · 2023-08-04T20:41:53Z

It apparently does: https://github.com/Quansight-Labs/ndindex/actions/runs/5766363872/job/15634144314?pr=161#step:5:30. It looks like there are 3.12 manylinux builds on pypi https://pypi.org/project/coverage/#files, so it is grabbing that.

asmeurer · 2023-08-04T20:44:04Z

Here's coverage debug sys:

  coverage debug sys
-- sys -------------------------------------------------------
               coverage_version: 7.2.7
                coverage_module: /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/lib/python3.12/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/ndindex/ndindex/.coveragerc
                    config_file: /home/runner/work/ndindex/ndindex/.coveragerc
                config_contents: b'[run]\nomit =\n    ndindex/_version.py\n    ndindex/tests/doctest.py\n    ndindex/tests/test_no_dependencies.py\n\n[report]\nexclude_lines =\n    raise NotImplementedError\n    pragma: no cover\n    raise AssertionError\n    except NotImplementedError:\n\n# Require full coverage. Lines that cannot be covered can be added as regexes\n# above, or excluded using # pragma: no cover\nfail_under = 100\n'
                      data_file: -none-
                         python: 3.12.0b4 (main, Jul 12 2023, 06:20:24) [GCC 11.3.0]
                       platform: Linux-5.15.0-1042-azure-x86_64-with-glibc2.35
                 implementation: CPython
                     executable: /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/bin/python
                   def_encoding: utf-8
                    fs_encoding: utf-8
                            pid: 1789
                            cwd: /home/runner/work/ndindex/ndindex
                           path: /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/bin
                                 /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/lib/python312.zip
                                 /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/lib/python3.12
                                 /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/lib/python3.12/lib-dynload
                                 /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/lib/python3.12/site-packages
                    environment: HOME = /home/runner
                   command_line: /opt/hostedtoolcache/Python/3.12.0-beta.4/x64/bin/coverage debug sys
         sqlite3_sqlite_version: 3.37.2
             sqlite3_temp_store: 0
        sqlite3_compile_options: ATOMIC_INTRINSICS=1, COMPILER=gcc-11.3.0, DEFAULT_AUTOVACUUM,
                                 DEFAULT_CACHE_SIZE=-2000, DEFAULT_FILE_FORMAT=4,
                                 DEFAULT_JOURNAL_SIZE_LIMIT=-1, DEFAULT_MMAP_SIZE=0, DEFAULT_PAGE_SIZE=4096,
                                 DEFAULT_PCACHE_INITSZ=20, DEFAULT_RECURSIVE_TRIGGERS,
                                 DEFAULT_SECTOR_SIZE=4096, DEFAULT_SYNCHRONOUS=2,
                                 DEFAULT_WAL_AUTOCHECKPOINT=1000, DEFAULT_WAL_SYNCHRONOUS=2,
                                 DEFAULT_WORKER_THREADS=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_MATH_FUNCTIONS,
                                 ENABLE_PREUPDATE_HOOK, ENABLE_RTREE, ENABLE_SESSION, ENABLE_STMTVTAB,
                                 ENABLE_UNLOCK_NOTIFY, ENABLE_UPDATE_DELETE_LIMIT, HAVE_ISNAN,
                                 LIKE_DOESNT_MATCH_BLOBS, MALLOC_SOFT_LIMIT=1024, MAX_ATTACHED=10,
                                 MAX_COLUMN=2000, MAX_COMPOUND_SELECT=[50](https://github.com/Quansight-Labs/ndindex/actions/runs/5766385439/job/15634216577?pr=161#step:5:51)0, MAX_DEFAULT_PAGE_SIZE=32768,
                                 MAX_EXPR_DEPTH=1000, MAX_FUNCTION_ARG=127, MAX_LENGTH=1000000000,
                                 MAX_LIKE_PATTERN_LENGTH=50000, MAX_MMAP_SIZE=0x7fff0000,
                                 MAX_PAGE_COUNT=1073741823, MAX_PAGE_SIZE=65[53](https://github.com/Quansight-Labs/ndindex/actions/runs/5766385439/job/15634216577?pr=161#step:5:54)6, MAX_SCHEMA_RETRY=25,
                                 MAX_SQL_LENGTH=1000000000, MAX_TRIGGER_DEPTH=1000,
                                 MAX_VARIABLE_NUMBER=250000, MAX_VDBE_OP=250000000, MAX_WORKER_THREADS=8,
                                 MUTEX_PTHREADS, OMIT_LOOKASIDE, SECURE_DELETE, SOUNDEX, SYSTEM_MALLOC,
                                 TEMP_STORE=1, THREADSAFE=1, USE_URI

(from https://github.com/Quansight-Labs/ndindex/actions/runs/5766385439/job/15634216577?pr=161#step:5:48)

nedbat · 2023-08-05T00:33:47Z

This is a mystery. I forked your repo (https://github.com/nedbat/ndindex) and hacked away at it. Now I have a file (justdoit.py) that sets a do-nothing trace function, and runs one of your tests: https://github.com/nedbat/ndindex/actions/runs/5767689409. On 3.11, it takes 14sec. On 3.12, it takes 43sec. I don't know why. We could toss this over to CPython to diagnose. They will probably want to take a look.

nedbat · 2023-08-05T22:12:53Z

I've reported this in CPython: python/cpython#107674

tarpas · 2023-10-24T15:22:44Z

On 3.11, it takes 14sec. On 3.12, it takes 43sec. I don't know why. We could toss this over to CPython to diagnose. They will probably want to take a look.

This is with the C extension? At CPython they had a look and didn't do anything for 3.12.0. There are some hopes that coveragepy will switch to the new monitoring API for 3.12 but I didn't find any trace supporting that hope here in coveragepy repo. Is there hope :)? python/cpython#107841 (comment)

nedbat · 2023-10-24T21:09:11Z

I've pinged the core dev on the CPython issue. I have started on code to use the new PEP 669 monitoring, but I haven't made much progress on it. I'd welcome help.

intgr · 2024-02-10T17:18:32Z

For anyone else still struggling with this and who missed the changelog:

coverage 7.4.0 includes experimental support for PEP 669 that can be enabled with COVERAGE_CORE=sysmon environment variable, which already speeds up line coverage.

asmeurer · 2024-02-12T21:44:06Z

Thanks for the tip. This would be a lot easier to use if that variable were just ignored for Python 3.11 and lower. Right now, setting it causes those versions to raise an exception.

nedbat · 2024-02-13T12:17:53Z

This would be a lot easier to use if that variable were just ignored for Python 3.11 and lower. Right now, setting it causes those versions to raise an exception.

Yes, I've gotten that feedback, and there's a PR: #1747. I'll figure out how to make that right soon.

asmeurer · 2024-02-13T23:24:32Z

This flag has indeed made the coverage runs for 3.12 way faster. They now run in about the same amount of time as when coverage is disabled! https://github.com/Quansight-Labs/ndindex/actions/runs/7892990262/usage

Here's coverage disabled completely for comparison:

Python 3.12 introduced a new (much faster) way of tracking and monitoring execution of python code by tools like coverage tracking using sysmon (PEP 669). This however also apparently heavily impacted performance of coverage tracking for Python 3.12 when PEP 669 is not used. The coverage library since 7.4.0 has an experimental support for PEP 669 that can be enabled with COVERAGE_CORE=sysmon env variable and a number of users confirmed it fixes the problem. We are using 7.4.4 coverage already so we should enable this mode to speed up our coverage tracking. That should also allow us to remove databricks from excluded providers. See databricks/databricks-sql-python#369 for databricks case and nedbat/coveragepy#1665 for coverage bug.

) Python 3.12 introduced a new (much faster) way of tracking and monitoring execution of python code by tools like coverage tracking using sysmon (PEP 669). This however also apparently heavily impacted performance of coverage tracking for Python 3.12 when PEP 669 is not used. The coverage library since 7.4.0 has an experimental support for PEP 669 that can be enabled with COVERAGE_CORE=sysmon env variable and a number of users confirmed it fixes the problem. We are using 7.4.4 coverage already so we should enable this mode to speed up our coverage tracking. That should also allow us to remove databricks from excluded providers. See databricks/databricks-sql-python#369 for databricks case and nedbat/coveragepy#1665 for coverage bug.

@trent-codecov

Solution from nedbat/coveragepy#1665 (comment) Thanks @trent-codecov for the suggestion.

@trent-codecov

* copy changes from #285 I'm copying the changes because that PR is far behind `main`. We will probably wait for the base image change to happen before merging this update work though * upgrade packages until project builds and tests run * fix tests * disable mutation testing * fix: Fix pytest-cov performance Solution from nedbat/coveragepy#1665 (comment) Thanks @trent-codecov for the suggestion.

ogrisel · 2024-07-10T07:57:00Z

Contrary to what others reported, the COVERAGE_CORE=sysmon option seems to degrade performance even further when running the scikit-learn tests with coverage enabled on CPython 3.12 (at least under Linux):

CI Update pylatest-pip-openblas-pandas build to Python 3.11 scikit-learn/scikit-learn#29444 (comment)

…194) Python 3.12 introduced a new (much faster) way of tracking and monitoring execution of python code by tools like coverage tracking using sysmon (PEP 669). This however also apparently heavily impacted performance of coverage tracking for Python 3.12 when PEP 669 is not used. The coverage library since 7.4.0 has an experimental support for PEP 669 that can be enabled with COVERAGE_CORE=sysmon env variable and a number of users confirmed it fixes the problem. We are using 7.4.4 coverage already so we should enable this mode to speed up our coverage tracking. That should also allow us to remove databricks from excluded providers. See databricks/databricks-sql-python#369 for databricks case and nedbat/coveragepy#1665 for coverage bug. GitOrigin-RevId: dffc9e3fa83e3cd910a83e7c505fe23b26feddf2

asmeurer added bug Something isn't working needs triage labels Aug 4, 2023

nedbat removed the needs triage label Aug 4, 2023

nedbat mentioned this issue Aug 5, 2023

sys.settrace dramatic slowdown in 3.12 python/cpython#107674

Open

2 tasks

nedbat added the cpython Reported as a bug in CPython label Aug 5, 2023

nedbat closed this as completed Aug 8, 2023

nedbat closed this as not planned Won't fix, can't repro, duplicate, stale Aug 8, 2023

tybug mentioned this issue Oct 26, 2023

Use sys.monitoring for scrutineer on 3.12 HypothesisWorks/hypothesis#3776

Merged

alexander-beedie mentioned this issue Nov 15, 2023

build(python): Support Python 3.12 pola-rs/polars#12094

Merged

berquist mentioned this issue Jan 22, 2024

code coverage is very slow with Python 3.12 cclib/cclib#1347

Open

intgr mentioned this issue Feb 9, 2024

Use PEP 669 Low Impact Monitoring to reduce overhead #1746

Open

nicoddemus mentioned this issue Feb 14, 2024

Memory Leak Python 3.12.2 pytest-dev/pytest-cov#628

Closed

alexei mentioned this issue Mar 7, 2024

Bug Report: execution time increased by ~33% with 3.12 image CircleCI-Public/cimg-python#232

Open

susodapop mentioned this issue Mar 15, 2024

Extremely slow import times on Python 3.12 databricks/databricks-sql-python#369

Closed

potiuk mentioned this issue Mar 15, 2024

Improve speed and stability of Python 3.12 tests in canary build apache/airflow#38194

Merged

eladkal mentioned this issue Mar 16, 2024

Restore Python 3.12 support for Databricks apache/airflow#38207

Merged

giovanni-guidini added a commit to codecov/worker that referenced this issue Apr 29, 2024

fix: Fix pytest-cov performance

a0e1cad

Solution from nedbat/coveragepy#1665 (comment) Thanks @trent-codecov for the suggestion.

tomwhite mentioned this issue Jun 10, 2024

Expose Lithops wait_dur_sec to speed up tests cubed-dev/cubed#456

Merged

mattjamc mentioned this issue Jun 21, 2024

Tp2000 1327 upgrade python 3.12 uktrade/tamato#1246

Merged

This was referenced Jul 9, 2024

Fix tests for numpy 2 and array api compat scikit-learn/scikit-learn#29436

Merged

CI Update pylatest-pip-openblas-pandas build to Python 3.11 scikit-learn/scikit-learn#29444

Merged

lesteve mentioned this issue Jul 10, 2024

COVERAGE_CORE=sysmon with branch coverage can be 2x slower than default in some cases #1812

Open

desertaxle mentioned this issue Nov 1, 2024

Set COVERAGE_CORE=sysmon to speed up test on 3.12 PrefectHQ/prefect#15905

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Poor performance in Python 3.12 #1665

Poor performance in Python 3.12 #1665

asmeurer commented Aug 4, 2023 •

edited

Loading

nedbat commented Aug 4, 2023

asmeurer commented Aug 4, 2023

asmeurer commented Aug 4, 2023

nedbat commented Aug 5, 2023

nedbat commented Aug 5, 2023

tarpas commented Oct 24, 2023

nedbat commented Oct 24, 2023

intgr commented Feb 10, 2024 •

edited

Loading

asmeurer commented Feb 12, 2024

nedbat commented Feb 13, 2024

asmeurer commented Feb 13, 2024 •

edited

Loading

ogrisel commented Jul 10, 2024 •

edited

Loading

Poor performance in Python 3.12 #1665

Poor performance in Python 3.12 #1665

Comments

asmeurer commented Aug 4, 2023 • edited Loading

nedbat commented Aug 4, 2023

asmeurer commented Aug 4, 2023

asmeurer commented Aug 4, 2023

nedbat commented Aug 5, 2023

nedbat commented Aug 5, 2023

tarpas commented Oct 24, 2023

nedbat commented Oct 24, 2023

intgr commented Feb 10, 2024 • edited Loading

asmeurer commented Feb 12, 2024

nedbat commented Feb 13, 2024

asmeurer commented Feb 13, 2024 • edited Loading

ogrisel commented Jul 10, 2024 • edited Loading

asmeurer commented Aug 4, 2023 •

edited

Loading

intgr commented Feb 10, 2024 •

edited

Loading

asmeurer commented Feb 13, 2024 •

edited

Loading

ogrisel commented Jul 10, 2024 •

edited

Loading