Speeding up collection phase

[ksolo]

I'm working on an open source projected called GitCoin and have been trying to develop via TDD but the collection phase of pytest startup is taking an excruciatingly long time to complete. I added a pytest.ini that I had hoped would speed things up by ignoring many of the directories that did not contain tests and did get a 15s improvement (running a single file test went from 90s - 75s).

We use docker for development and I am wondering if recursing through the filesystem in that context is causing the issue. I'm currently working on setting the app up without the container to see if that resolves it, but would appreciate any tips for ways we could improve the startup times, especially for the case of running a single file for active development on new features.

[bluetech]

We have done some optimizations to the collection phase recently, that will be included in the pytest 7.0 release. If you can try installing pytest from git, I will be interested to know if it improves things for you. Other than that, we can look at profiles of collection on this project and see if anything stands out.

To install pytest from git use pip install git+https://github.com/pytest-dev/pytest.git.

BTW, which Python version and OS are you using?

[ksolo]

I'm running again, this type with a specific test file to see how that impacts the report.

[ksolo]

Unfortunately every time I run pyinstrument with a specific test file the process is being killed before it completes. I'll try the cProfile and see what information that can provide.

[ksolo]

Here are all the items that had a cumulative time > 10s

 Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   4048/1    0.131    0.000  163.704  163.704 {built-in method builtins.exec}
        1    0.000    0.000  163.704  163.704 pytest:3(<module>)
        1    0.000    0.000  161.186  161.186 __init__.py:178(console_main)
        1    0.000    0.000  161.186  161.186 __init__.py:130(main)
  7820/53    0.126    0.000  160.769    3.033 manager.py:90(_hookexec)
  7820/53    0.200    0.000  160.768    3.033 manager.py:84(<lambda>)
  7820/53    0.489    0.000  160.766    3.033 callers.py:157(_multicall)
   7596/2    0.362    0.000  160.727   80.364 hooks.py:272(__call__)
 4223/566    0.250    0.000   97.738    0.173 <frozen importlib._bootstrap>:966(_find_and_load)
 4057/429    0.192    0.000   97.534    0.227 <frozen importlib._bootstrap>:936(_find_and_load_unlocked)
 3660/298    0.213    0.000   95.733    0.321 <frozen importlib._bootstrap>:651(_load_unlocked)
  613/539    0.015    0.000   94.791    0.176 __init__.py:108(import_module)
  667/539    0.016    0.000   94.773    0.176 <frozen importlib._bootstrap>:982(_gcd_import)
        1    0.000    0.000   86.742   86.742 __init__.py:297(_prepareconfig)
        1    0.000    0.000   86.283   86.283 __init__.py:999(pytest_cmdline_parse)
        1    0.000    0.000   86.283   86.283 __init__.py:1275(parse)
        1    0.000    0.000   86.193   86.193 __init__.py:1149(_preparse)
 4467/373    0.070    0.000   85.325    0.229 <frozen importlib._bootstrap>:211(_call_with_frames_removed)
 3251/295    0.084    0.000   77.562    0.263 <frozen importlib._bootstrap_external>:672(exec_module)
      335    0.021    0.000   77.537    0.231 __init__.py:1(<module>)
        1    0.000    0.000   74.443   74.443 main.py:315(pytest_cmdline_main)
        1    0.000    0.000   74.443   74.443 main.py:256(wrap_session)
        1    0.000    0.000   73.349   73.349 main.py:319(_main)
        1    0.000    0.000   73.344   73.344 main.py:332(pytest_collection)
        1    0.001    0.001   73.344   73.344 main.py:579(perform_collect)
      266    0.015    0.000   72.158    0.271 runner.py:455(collect_one_node)
      266    0.013    0.000   71.524    0.269 runner.py:340(pytest_make_collect_report)
      266    0.020    0.000   71.495    0.269 runner.py:298(from_call)
      266    0.009    0.000   71.443    0.269 runner.py:341(<lambda>)
        1    0.000    0.000   57.893   57.893 plugin.py:258(pytest_load_initial_conftests)
        2    0.000    0.000   56.352   28.176 plugin.py:221(_setup_django)
        1    0.000    0.000   56.351   56.351 __init__.py:8(setup)
        1    0.003    0.003   56.319   56.319 registry.py:61(populate)
7258/3952    0.097    0.000   55.775    0.014 {method 'extend' of 'list' objects}
 1905/426    0.053    0.000   53.853    0.126 main.py:799(genitems)
       73    0.002    0.000   42.315    0.580 config.py:204(import_models)
   259/80    0.044    0.000   40.035    0.500 rewrite.py:130(exec_module)
 1273/473    0.026    0.000   37.183    0.079 {built-in method builtins.__import__}
      166    0.269    0.002   32.090    0.193 python.py:700(collect)
18083/11433    0.397    0.000   28.923    0.003 <frozen importlib._bootstrap>:997(_handle_fromlist)
     3438    0.706    0.000   28.204    0.008 __init__.py:515(_getconftestmodules)
        1    0.006    0.006   26.367   26.367 manager.py:280(load_setuptools_entrypoints)
       10    0.001    0.000   25.999    2.600 __init__.py:188(load)
     4660    0.221    0.000   25.449    0.005 main.py:515(gethookproxy)
9344/9003    0.403    0.000   24.820    0.003 {built-in method builtins.__build_class__}
     1914    0.175    0.000   24.118    0.013 python.py:676(_collectfile)
     3862    0.083    0.000   23.569    0.006 re.py:286(_compile)
     1025    0.015    0.000   23.438    0.023 re.py:231(compile)
      832    0.059    0.000   23.310    0.028 sre_compile.py:557(compile)
    38382    1.012    0.000   22.296    0.001 local.py:379(check)
      259    0.023    0.000   21.977    0.085 rewrite.py:348(_rewrite_test)
      259    0.007    0.000   21.301    0.082 rewrite.py:411(rewrite_asserts)
      259    4.267    0.016   21.286    0.082 rewrite.py:671(run)
      120    0.142    0.001   18.740    0.156 main.py:646(collect)
       24    0.003    0.000   17.915    0.746 __init__.py:3(<module>)
      832    0.029    0.000   17.561    0.021 sre_compile.py:542(_code)
       32    0.004    0.000   17.389    0.543 models.py:1(<module>)
 8927/832    1.432    0.000   17.051    0.020 sre_compile.py:64(_compile)
    22372    0.441    0.000   16.336    0.001 common.py:318(isfile)
    50486   16.087    0.000   16.087    0.000 {built-in method posix.stat}
       51    0.003    0.000   15.990    0.314 python.py:502(collect)
        2    0.002    0.001   15.357    7.678 models.py:18(<module>)
    22745    0.502    0.000   15.246    0.001 genericpath.py:27(isfile)
3898/3527    0.068    0.000   14.179    0.004 python.py:286(obj)
        8    0.004    0.001   14.139    1.767 __init__.py:19(<module>)
       51    0.002    0.000   14.074    0.276 python.py:508(_inject_setup_module_fixture)
       51    0.001    0.000   14.056    0.276 python.py:499(_getobj)
       51    0.002    0.000   14.056    0.276 python.py:574(_importtestmodule)
       51    0.010    0.000   14.044    0.275 pathlib.py:451(import_path)
        9    0.002    0.000   13.520    1.502 models.py:19(<module>)
      996    0.081    0.000   13.459    0.014 main.py:543(_collectfile)
     4164    0.511    0.000   13.270    0.003 <frozen importlib._bootstrap>:870(_find_spec)
     2438    0.119    0.000   11.465    0.005 sre_compile.py:223(_compile_charset)
 3022/540    0.077    0.000   11.426    0.021 ast.py:249(visit)
      540    0.091    0.000   11.407    0.021 rewrite.py:838(visit_Assert)
     2438    3.168    0.001   11.190    0.005 sre_compile.py:250(_optimize_charset)
        5    0.001    0.000   10.775    2.155 validators.py:1(<module>)
        1    0.000    0.000   10.698   10.698 validators.py:9(URIValidator)
     2759    0.045    0.000   10.467    0.004 rewrite.py:531(set_location)
73727/2759    2.341    0.000   10.423    0.004 rewrite.py:534(_fix)

[ksolo]

@RonnyPfannschmidt @bluetech I think this issue is 100% rooted in the use of Docker for Mac. I spend yesterday setting up the application without the container and collection times dropped from > 55s to around 1.3s, which is totally reasonable. I really appreciate you taking the time to chat with me about it.

[RonnyPfannschmidt]

@ksolo thanks for the followup, docker on osx is indeed a confusing time cost center