Possible performance regression with Coverage >=5 · Issue #1037 · nedbat/coveragepy (original) (raw)
Describe the bug
Total coverage run time is considerable bigger in Coverage 5, as compared to 4.5.3
To Reproduce
How can we reproduce the problem? Please be specific. Don't just link to a failing CI job. Answer the questions below:
- What version of Python are you using?
3.6.7 - What version of coverage.py are you using? The output of
coverage debug sysis helpful.
Both versions of Coverage are installed withpip.
For Coverage5.3:
-- sys -------------------------------------------------------
version: 5.3
coverage: w:\1\projects\coverage-test\lib\site-packages\coverage\__init__.py
tracer: -none-
CTracer: available
plugins.file_tracers: -none-
plugins.configurers: -none-
plugins.context_switchers: -none-
configs_attempted: .coveragerc
setup.cfg
tox.ini
pyproject.toml
configs_read: -none-
config_file: None
config_contents: -none-
data_file: -none-
python: 3.6.7 (default, Mar 4 2020, 17:08:00) [MSC v.1900 64 bit (AMD64)]
platform: Windows-10-10.0.19041-SP0
implementation: CPython
executable: w:\1\projects\coverage-test\scripts\python.exe
def_encoding: utf-8
fs_encoding: utf-8
pid: 17812
cwd: W:\1\Projects\coverage-test
path: W:\1\Projects\coverage-test\Scripts\coverage.exe
w:\1\projects\coverage-test\scripts\python36.zip
W:\Miniconda\DLLs
W:\Miniconda\lib
W:\Miniconda
w:\1\projects\coverage-test
w:\1\projects\coverage-test\lib\site-packages
environment: CONDA_PY = 36
command_line: W:\1\Projects\coverage-test\Scripts\coverage debug sys
sqlite3_version: 2.6.0
sqlite3_sqlite_version: 3.21.0
sqlite3_temp_store: 0
sqlite3_compile_options: COMPILER=msvc-1900
ENABLE_FTS4
ENABLE_FTS5
THREADSAFE=1
For Coverage 4.5.3:
-- sys -------------------------------------------------------
version: 4.5.3
coverage: w:\1\projects\coverage-test\lib\site-packages\coverage\__init__.py
cover_paths: W:\1\Projects\coverage-test\Lib\site-packages\coverage
pylib_paths: W:\Miniconda\Lib
tracer: CTracer
plugins.file_tracers: -none-
plugins.configurers: -none-
config_files: .coveragerc
setup.cfg
tox.ini
configs_read: -none-
data_path: W:\1\Projects\coverage-test\.coverage
python: 3.6.7 (default, Mar 4 2020, 17:08:00) [MSC v.1900 64 bit (AMD64)]
platform: Windows-10-10.0.19041-SP0
implementation: CPython
executable: w:\1\projects\coverage-test\scripts\python.exe
cwd: W:\1\Projects\coverage-test
path:
w:\1\projects\coverage-test\scripts\python36.zip
W:\Miniconda\DLLs
W:\Miniconda\lib
W:\Miniconda
w:\1\projects\coverage-test
w:\1\projects\coverage-test\lib\site-packages
environment: -none-
command_line: W:\1\Projects\coverage-test\Scripts\coverage debug sys
source_match: -none-
source_pkgs_match: -none-
include_match: -none-
omit_match: -none-
cover_match: W:\1\Projects\coverage-test\Lib\site-packages\coverage
pylib_match: W:\Miniconda\Lib
- What versions of what packages do you have installed? The output of
pip freezeis helpful.
Other than Coverage itself, these are the packages:
atomicwrites==1.4.0
attrs==20.2.0
colorama==0.4.3
coverage==5.3
importlib-metadata==2.0.0
iniconfig==1.0.1
packaging==20.4
pluggy==0.13.1
py==1.9.0
pyparsing==2.4.7
pytest==6.1.1
six==1.15.0
toml==0.10.1
zipp==3.3.0
- What code are you running? Give us a specific commit of a specific repo that we can check out.
I'm running a single pytest test module:
def test_dummy(): assert True
- What commands did you run?
I wrote the following script to output the Coverage version, run coverage + pytest (without pytest-cov) on my single test module, then print the time the command took. The catch here is that I'm adding the pandas source codebase via --source, even though my test doesn't use pandas and indeed the package isn't even installed. I've currently found that this addition makes the command take way longer. I'm doing this for the purposes of this bug report, as an attempt to make the bug "easily" reproducible, but the problem was first identified when running coverage on a proprietary codebase.
Here's the script:
import subprocess import time
subprocess.run(['coverage', '--version'])
command = r'coverage run --source=../pandas/pandas,src -m pytest src/test_dummy.py' start = time.time() subprocess.run(command.split(' ')) end = time.time() print(f'Time: {end-start} s')
Here's the output with Coverage 4.5.3:
(coverage-test) λ python time_cov.py
Coverage.py, version 4.5.3 with C extension
Documentation at https://coverage.readthedocs.io
============================================================================================================ test session starts ============================================================================================================
platform win32 -- Python 3.6.7, pytest-6.1.1, py-1.9.0, pluggy-0.13.1
rootdir: W:\1\Projects\coverage-test
collected 1 item
src\test_dummy.py . [100%]
============================================================================================================= 1 passed in 0.01s =============================================================================================================
Time: 0.4677555561065674 s
Here's the output with Coverage 5.3:
(coverage-test) λ python time_cov.py
Coverage.py, version 5.3 with C extension
Full documentation is at https://coverage.readthedocs.io
============================================================================================================ test session starts ============================================================================================================
platform win32 -- Python 3.6.7, pytest-6.1.1, py-1.9.0, pluggy-0.13.1
rootdir: W:\1\Projects\coverage-test
collected 1 item
src\test_dummy.py . [100%]
============================================================================================================= 1 passed in 0.01s =============================================================================================================
Time: 5.179388761520386 s
Expected behavior
I expected Coverage 5.3 to take as much time as 4.5.3 (half a second), but the command took 5 seconds.
Additional context
None that I can think of right now! Please let me know if more info is needed