problem with fixture finalizers

[antonyc]

We're using pytest-timeout, thanks. The pytehon official documentation suggests using finalizers to learn the status of the test call. And this is what we're trying to do. We got this code:

@pytest.fixture(scope="function", autouse=True)
def do_something_on_failure(request):
    yield

    if not request.node.rep_call.failed:
        return  # do nothing
    .... actually handle this ...

We're using asyncio-0.18.3, anyio-3.5.0, timeout-2.1.0, order-1.0.1. In case of timeout we get traces like this:

+++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
tests/test_workers.py::test_availability_checker ERROR
tests/test_workers.py::test_availability_checker ERROR
tests/management_api/test_pageserver.py::test_register_new_pageserver PASSED

==================================== ERRORS ====================================
__________________ ERROR at setup of test_role_password_reset __________________
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/opt/hostedtoolcache/Python/3.9.12/x64/lib/python3.9/asyncio/base_events.py:634: in run_until_complete
    self.run_forever()
        future     = <Task pending name='Task-236' coro=<_wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.setup() running at /home/runner/work/cloud/cloud/tests_e2e/.venv/lib/python3.9/site-packages/pytest_asyncio/plugin.py:275> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f6854ae8ee0>()]>>
        new_task   = True
        self       = <_UnixSelectorEventLoop running=False closed=False debug=False>
/opt/hostedtoolcache/Python/3.9.12/x64/lib/python3.9/asyncio/base_events.py:601: in run_forever
    self._run_once()
        old_agen_hooks = asyncgen_hooks(firstiter=None, finalizer=None)
        self       = <_UnixSelectorEventLoop running=False closed=False debug=False>
/opt/hostedtoolcache/Python/3.9.12/x64/lib/python3.9/asyncio/base_events.py:1869: in _run_once
    event_list = self._selector.select(timeout)
        sched_count = 1
        self       = <_UnixSelectorEventLoop running=False closed=False debug=False>
        timeout    = 1.9999875999999972
        when       = 362.29601465
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <selectors.EpollSelector object at 0x7f68549f92b0>, timeout = 2.0

    def select(self, timeout=None):
        if timeout is None:
            timeout = -1
        elif timeout <= 0:
            timeout = 0
        else:
            # epoll_wait() has a resolution of 1 millisecond, round away
            # from zero to wait *at least* timeout seconds.
            timeout = math.ceil(timeout * 1e3) * 1e-3

        # epoll_wait() expects `maxevents` to be greater than zero;
        # we want to make sure that `select()` can be called when no
        # FD is registered.
        max_ev = max(len(self._fd_to_key), 1)

        ready = []
        try:
>           fd_event_list = self._selector.poll(timeout, max_ev)
E           Failed: Timeout >120.0s

max_ev     = 1
ready      = []
self       = <selectors.EpollSelector object at 0x7f68549f92b0>
timeout    = 2.0

/opt/hostedtoolcache/Python/3.9.12/x64/lib/python3.9/selectors.py:469: Failed

... skipped internal logs ...

________________ ERROR at teardown of test_role_password_reset _________________

>       if not request.node.rep_call.failed:
E       AttributeError: 'Function' object has no attribute 'rep_call'

request    = <SubRequest 'do_something_on_failure' for <Function test_role_password_reset>>

fixtures/project.py:48: AttributeError

I skipped some internal logs, but tried to leave the most needed.

So is this a known problem? To me it looks like timeout happened in some test test_availability_checker, and then pytest tried to run setup and teardown of another test test_role_password_reset, right? Is this related to pytest-timeout at all?

[flub]

I suspect that your problem is that the timeout occurs in the setup and not in the call, and this is why pytest is not adding the rep_call attribute because call just never happened. You can fix this by being more defensive and not always expecting the attribute to be present, e.g. getattr(request.node, 'rep_call') or so. If you want to detect the failure of setup maybe there's a similar attribute for setup to inspect?

[antonyc]

Yeah, sure, that was the solution I used to escape the tracebacks in logs, thank you. But, I would like to know, if there is a programmatic way to catch this Timeout for example, if one has the ability to catch SoftTimeLimitExceeded in Celery (sorry, if I mention the code you haven't seen yet): https://docs.celeryq.dev/en/stable/userguide/workers.html#time-limits

That would be a clearer way to my mind: just catch exceptions and not perform any assumption about attribute existence.

[flub]

pytest-timeout simply calls pytest.fail() if you use the SIGALRM method, which you appear to be using. In turn that raises pytest.fail.Exception.

Where are you planning to catch this though?

[flub]

Forgot the code link: https://github.com/pytest-dev/pytest-timeout/blob/0a3e9a9554b7277507aff26d208e1f4e7367c3ce/pytest_timeout.py#L409