Tests collection is slow on high number of tests

[Nepherhotep]

Hi,

We have over 15k tests in the repository, and recently switched from nosetests to pytest. Apparently, tests collection in pytest is way slower than in nosetests - 130s vs 30s. Also, I need to mention that norecursedirs and testpaths parameters are both set, just to exclude the case of walking in .git or other unrelated directories.
It's also interesting, that the number of collected tests is asymptotic to time:

I tried to profile it using pyflame and cProfile, it seems like the slowest part is calling node.py:FixtureManager._matchfactories method call:

Here is a callgraph:

When I tried to log, what's is happening, it seems like, the more tests, the more method is called with polynomial dependency.

Going deeper into _matchfactories method, I was able to reduce collection time from 130s to 85s just by caching the results of _splitnode method:

diff --git a/src/_pytest/nodes.py b/src/_pytest/nodes.py
index 491cf9d2c..62eb66086 100644
--- a/src/_pytest/nodes.py
+++ b/src/_pytest/nodes.py
@@ -13,6 +13,9 @@ SEP = "/"
 tracebackcutdir = py.path.local(_pytest.__file__).dirpath()
 
 
+_node_cache = {}
+
+
 def _splitnode(nodeid):
     """Split a nodeid into constituent 'parts'.
 
@@ -31,9 +34,13 @@ def _splitnode(nodeid):
     if nodeid == "":
         # If there is no root node at all, return an empty list so the caller's logic can remain sane
         return []
-    parts = nodeid.split(SEP)
-    # Replace single last element 'test_foo.py::Bar' with multiple elements 'test_foo.py', 'Bar'
-    parts[-1:] = parts[-1].split("::")
+
+    parts = _node_cache.get(nodeid)
+    if not parts:
+        parts = nodeid.split(SEP)
+        # Replace single last element 'test_foo.py::Bar' with multiple elements 'test_foo.py', 'Bar'
+        parts[-1:] = parts[-1].split("::")
+        _node_cache[nodeid] = parts
     return parts

It doesn't solve the asymptotic problem, but just making _splitnode and thus _matchfactories method faster:

Please let me know if you think there could be a better way to fix the problem.

Thanks!
Alex

[nicoddemus]

Thanks @Nepherhotep for the report.

I think a cache there wouldn't hurt (might even use @lru_cache(maxsize=None) instead), but I think it would be worth to investigate this a little further to see if we can have more gains.

Would it be possible to share the output of pytest --collect-only so we can reproduce your test tree with dummy tests? I imagine this would facilitate debugging and improving performance there.

[Nepherhotep]

Thanks @nicoddemus
It will take me a while to obfuscate data, but I'll prepare the output soon.

Thanks!

[Nepherhotep]

collected_tests.txt

Hi @nicoddemus,

Please see the file attached.
As for cache, if I want it to be in 4.6-maintenance branch as well, do I need to submit two different PRs - lru_cache for "master" and dict-based cache to "4.6-maintenance" (as lru_cache is not supported by 2.7 yet)?

[nicoddemus]

Thanks, I will take a look

As for cache, if I want it to be in 4.6-maintenance branch as well, do I need to submit two different PRs - lru_cache for "master" and dict-based cache to "4.6-maintenance" (as lru_cache is not supported by 2.7 yet)?

Actually I don't think this qualifies to go to 4.6-maintenance, as this is an improvement and 4.6-maintenance is about critical bug-fixes only for the 4.6 series.

[Nepherhotep]

Gotcha, that makes sense.

[bluetech]

I tried to reproduce the issue using collected_tests.txt but there is no difference -- just generating the test directory using the following script doesn't call _splitnodes. I think fixtures need to be used somewhere. Can you amend the script such that it reproduces the before/after results you got?

Also, since _splitnodes is only called from one function, ischildnode, it might be more worthwhile to optimize that.

---

import os

package, module = None, None
for line in open('collected_tests.txt'):
    if not line.strip():
        continue
    scope, name = line.strip()[1:-1].split(' ')
    if scope == 'Package':
        package = './' + name
        os.makedirs(package)
    elif scope == 'Module':
        module = open(package + '/' + name, 'w')
    elif scope == 'UnitTestCase':
        print(f'class {name}:\n    pass', file=module)
    elif scope == 'TestCaseFunction':
        print(f'    def {name}(self):\n        pass', file=module)

for root, dirs, files in os.walk('dir_0'):
    open(root + '/__init__.py', 'w')

[Nepherhotep]

@bluetech, I'd say, it's required to refactor getfixturedefs, which calls _matchfactories function polynomial amount of times, which causes a slowdown in performing quite simple calculations like splitting nodes.

[bluetech]

Sounds like it. If you can arrange a reproduction for this, I think it will be helpful.

Looking narrowly at how _matchfactories can be made faster, I am unsure about something. Is the following expected behavior? Are / and :: compatible in this way?

>>> _pytest.nodes.ischildnode(baseid='a/b/c/d', nodeid='a/b::c::d::e')
True

[nicoddemus]

FTR: Some work has been done in #5681 already thanks to @Nepherhotep.

[Nepherhotep]

@bluetech I'll try to create a fake repo, which is slow to collect.

@nicoddemus great thanks for guidance in that PR!