Slow `explain` phase for recursive strategy

[Forty-Bot]

Tests using the recursive strategy shrink very slowly. For example, this test

from hypothesis import given, strategies as st

@given(st.recursive(st.dictionaries(st.integers(0, 255), st.builds(object), min_size=2), 
                    lambda vals: st.dictionaries(st.integers(0, 255), vals, min_size=2)))
def test_recursive(trie):
    assert False

Takes over a minute to shrink:

$ pytest
=========================================================== test session starts ============================================================
platform linux -- Python 3.12.7, pytest-8.3.3, pluggy-1.5.0
rootdir: /path/to/pytest_example
plugins: hypothesis-6.119.2
collected 1 item                                                                                                                           

test_recursive.py F                                                                                                                  [100%]

================================================================= FAILURES =================================================================
______________________________________________________________ test_recursive ______________________________________________________________

    @given(st.recursive(st.dictionaries(st.integers(0, 255), st.builds(object), min_size=2),
>                       lambda vals: st.dictionaries(st.integers(0, 255), vals, min_size=2)))

test_recursive.py:4: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

trie = {0: <object object at 0x7faa12a02860>, 1: <object object at 0x7faa12a03e30>}

    @given(st.recursive(st.dictionaries(st.integers(0, 255), st.builds(object), min_size=2),
                        lambda vals: st.dictionaries(st.integers(0, 255), vals, min_size=2)))
    def test_recursive(trie):
>       assert False
E       assert False
E       Falsifying example: test_recursive(
E           trie={0: object(), 1: object()},  # or any other generated value
E       )

test_recursive.py:6: AssertionError
========================================================= short test summary info ==========================================================
FAILED test_recursive.py::test_recursive - assert False
======================================================= 1 failed in 76.41s (0:01:16) =======================================================

For comparison, shrinking just the base case takes only 1 second.

[Liam-DeVoe]

Slowness is due to the explain phase:

from hypothesis import given, strategies as st, settings, Phase
@given(
    st.recursive(
        st.dictionaries(st.integers(0, 255), st.just(None), min_size=2),
        lambda vals: st.dictionaries(st.integers(0, 255), vals, min_size=2),
    )
)
@settings(
    database=None,
    # phases=set(Phase) - {Phase.explain} # fast when uncommented
)
def f(trie):
    assert False
f()

I was worried this was due to the recent IR changes, but this is still slow on 6.118.1. I think probably we're just running a large number of examples relative to the shrinker for trivial test cases? And it doesn't help that the explain phase allows full generation, which is slow for large strategies like st.recursive, while the shrinker caps the size.

However, I did discover while looking into this that the explain phase runs under our coverage Tracer, and disabling that leads to a significant speedup - despite being on 3.12 sys.monitoring! We can't disable it entirely, of course, but returning sys.monitoring.DISABLED in trace_line for hypothesis files helps significantly. PR shortly.

[Liam-DeVoe]

@Forty-Bot could you check if the latest release is any better for you?

[Forty-Bot]

6.119.3 brings the time down to 25 seconds for me. Still not ideal. But maybe this is because of the slow data generation?

test_recursive.py::test_recursive:

  - during generate phase (0.63 seconds):
    - Typical runtimes: ~ 20-114 ms, of which ~ 2-90 ms in data generation
    - 0 passing examples, 10 failing examples, 0 invalid examples
    - Found 1 distinct error in this phase

  - during shrink phase (25.18 seconds):
    - Typical runtimes: ~ 3-600 ms, of which ~ 0-547 ms in data generation
    - 0 passing examples, 103 failing examples, 14 invalid examples
    - Tried 117 shrinks of which 0 were successful

  - Stopped because nothing left to do

[Zac-HD]

Ah, one obvious thing we should do here is split out the explain phase to a separate statistics bucket!