pytest test collection takes a lot of time (~10min for 2000 tests)

[ajeain]

• a detailed description of the bug or suggestion
  I have around 2000 tests, of which collection time takes ~10 min while running them takes 2.5 min.
• output of pip list from the virtual environment you are using
  $ pip3 list
  DEPRECATION: The default format will switch to columns in the future. You can use --format=(legacy|columns) (or define a format=(legacy|columns) in your pip.conf under the [list] section) to disable this warning.
  asn1crypto (0.24.0)
  atomicwrites (1.3.0)
  attrs (19.1.0)
  Automat (0.6.0)
  bcrypt (3.1.6)
  blinker (1.4)
  boto3 (1.9.111)
  botocore (1.12.111)
  certifi (2019.6.16)
  cffi (1.12.2)
  chardet (3.0.4)
  click (6.7)
  cloud-init (19.1)
  colorama (0.3.7)
  command-not-found (0.3)
  configobj (5.0.6)
  constantly (15.1.0)
  cryptography (2.6.1)
  decorator (4.4.0)
  dill (0.2.9)
  distro-info (0.18ubuntu0.18.04.1)
  docutils (0.14)
  hibagent (1.0.1)
  httplib2 (0.9.2)
  hyperlink (17.3.1)
  idna (2.8)
  importlib-metadata (0.21)
  incremental (16.10.1)
  Jinja2 (2.10)
  jmespath (0.9.4)
  jsonpatch (1.16)
  jsonpointer (1.10)
  jsonschema (2.6.0)
  keyring (10.6.0)
  keyrings.alt (3.0)
  language-selector (0.1)
  MarkupSafe (1.0)
  more-itertools (7.2.0)
  netifaces (0.10.4)
  oauthlib (2.0.6)
  packaging (19.1)
  PAM (0.4.2)
  paramiko (2.0.0)
  pip (9.0.1)
  pkg-resources (0.0.0)
  pluggy (0.12.0)
  py (1.8.0)
  pyasn1 (0.4.5)
  pyasn1-modules (0.2.1)
  pycparser (2.19)
  pycrypto (2.6.1)
  pygobject (3.26.1)
  PyJWT (1.5.3)
  PyNaCl (1.3.0)
  pyOpenSSL (17.5.0)
  pyparsing (2.4.2)
  pyserial (3.4)
  pytest (5.1.2)
  pytest-jira (0.3.11)
  pytest-reportportal (1.0.7)
  python-apt (1.6.4)
  python-dateutil (2.8.0)
  python-debian (0.1.32)
  pyxdg (0.25)
  PyYAML (3.12)
  reportportal-client (3.2.0)
  requests (2.22.0)
  requests-unixsocket (0.1.5)
  retry (0.9.2)
  s3transfer (0.2.0)
  SecretStorage (2.3.1)
  service-identity (16.0.0)
  setuptools (39.0.1)
  six (1.12.0)
  ssh-import-id (5.7)
  systemd-python (234)
  Twisted (17.9.0)
  ufw (0.36)
  unattended-upgrades (0.1)
  urllib3 (1.25.3)
  wcwidth (0.1.7)
  wheel (0.30.0)
  zipp (0.6.0)
  zope.interface (4.3.2)
• pytest and operating system versions
  5.1.2 on Ubuntu 18.04.3 LTS
• minimal example if possible

[The-Compiler]

Do you have a project or something where we can reproduce this? FWIW collecting 8000 tests takes around 4s here.

[ajeain]

what type of code do you need me to share? I am mainly using the "@pytest.mark.parametrize" way of inserting data into the tests, and also using the:
@pytest.mark.CI way of marking tests, although the long collection time happens also when not using the -m CI.
I am doing this before actually running the pytest line:
PYENV_HOME= xxxxxxxx
python3.6 -m venv PYENV_HOME --system-site-packages
. PYENV_HOME/bin/activate

and lastly:
python3.6 -m pytest -m CI --tb=short --jira -v -s

[The-Compiler]

Ideally, a full project where we can run pytest and see the issue. Since this doesn't happen to other people, it's probably something specific to your code.

Alternatively, you could run something like python3 -m cProfile -m pytest --collect-only to (hopefully) see what's the culprit.

[ajeain]

when running the above I get:
cProfile.py: error: no such option: -m
if doing:
pip3 install pytest-profiling
and running:
python3.6 -m pytest -m CI --collect-only --profile
I get an empty prof directory...
any idea?

[The-Compiler]

Oh, looks like -m for cProfile was added in Python 3.7. You could probably do something like python3 -m cProfile $(which pytest) --collect-only.

[ajeain]

plz see the following profile file and let me know where to start look at. It takes 10min just to collect the 1800 tests
profile-CI.txt

[The-Compiler]

Looking at that profile, something is doing network requests at import time. See e.g.:

       46    0.001    0.000  339.007    7.370 adapters.py:394(send)
       46    0.001    0.000  339.311    7.376 api.py:104(post)
       46    0.001    0.000  339.268    7.375 sessions.py:466(request)
       46    0.002    0.000  339.025    7.370 sessions.py:617(send)

[Zac-HD]

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000   41.799   41.799 test_aws_egress_only_internet_gateway.py:1(<module>)
        1    0.000    0.000    0.479    0.479 test_aws_instances.py:1(<module>)
        1    0.000    0.000   40.784   40.784 test_aws_internet_gateway.py:1(<module>)
        1    0.000    0.000    0.538    0.538 test_aws_nat_gateway.py:1(<module>)
        1    0.000    0.000   39.994   39.994 test_aws_network_acl.py:1(<module>)
        1    0.000    0.000    0.504    0.504 test_aws_network_interface.py:1(<module>)
        1    0.000    0.000   40.699   40.699 test_aws_route_tables.py:1(<module>)
        1    0.000    0.000    0.540    0.540 test_aws_security_groups.py:1(<module>)
        1    0.000    0.000    1.356    1.356 test_aws_subnets.py:1(<module>)
        1    0.000    0.000   16.470   16.470 test_aws_vpc.py:1(<module>)
        1    0.000    0.000   15.466   15.466 test_aws_vpc_peering_connection.py:1(<module>)
        1    0.000    0.000    7.274    7.274 test_aws_vpn_connection.py:1(<module>)
        1    0.000    0.000    0.512    0.512 test_aws_vpn_gateway.py:1(<module>)
        1    0.000    0.000   10.962   10.962 test_azure_crud_credentials.py:1(<module>)
        1    0.000    0.000   36.597   36.597 test_azure_firewalls.py:1(<module>)
        1    0.000    0.000   30.940   30.940 test_azure_network_interfaces.py:1(<module>)
        1    0.000    0.000   10.568   10.568 test_azure_route_tables.py:1(<module>)
        1    0.000    0.000   41.044   41.044 test_azure_security_groups.py:1(<module>)
        1    0.000    0.000   40.799   40.799 test_azure_vms.py:1(<module>)
        1    0.000    0.000   16.122   16.122 test_azure_vnets_subnets.py:1(<module>)
        1    0.000    0.000   24.853   24.853 test_azure_vpn_gateways.py:1(<module>)

Filtering the profile output for lines containing test_aws_ or test_azure_ will probably narrow this down enough to spot the function(s) making collection-time network requests.

I don't think this is a pytest bug though, so I'll close the issue.

[Syriiin]

Incase anyone else stumbles my variant of this issue, it might be that there is simply a very large directory included in the collection scope.
A 4.5gb directory with 158500 files took my test collection from less than a second to ~30s.
The --ignore flag or norecursedirs ini config can be used to ignore directories.

# pyproject.toml

[tool.pytest.ini_options]
norecursedirs = ["data"]