Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pytest fails while using version asyncio-0.15.0 #209

Closed
Kruszylo opened this issue Apr 19, 2021 · 20 comments
Closed

pytest fails while using version asyncio-0.15.0 #209

Kruszylo opened this issue Apr 19, 2021 · 20 comments

Comments

@Kruszylo
Copy link

Python: 3.8 (docker image)

My pytest setup:

...
============================= test session starts ==============================
platform linux -- Python 3.8.9, pytest-6.2.3, py-1.10.0, pluggy-0.13.1 -- /builds/.../venv/bin/python3
cachedir: .pytest_cache
hypothesis profile 'default' -> database=DirectoryBasedExampleDatabase('/builds/.../.hypothesis/examples')
rootdir: /builds/..., configfile: pytest.ini
plugins: hypothesis-6.9.2, asyncio-0.15.0
...

an error:

...
==================================== ERRORS ====================================
_____________________ ERROR at setup of test_async_ticker ______________________

fixturedef = <FixtureDef argname='event_loop' scope='function' baseid=''>
request = <SubRequest 'event_loop' for <Function test_async_ticker>>

    @pytest.hookimpl(hookwrapper=True)
    def pytest_fixture_setup(fixturedef, request):
        """Adjust the event loop policy when an event loop is produced."""
        if fixturedef.argname == "event_loop":
            outcome = yield
            loop = outcome.get_result()
            policy = asyncio.get_event_loop_policy()
>           old_loop = policy.get_event_loop()

venv/lib/python3.8/site-packages/pytest_asyncio/plugin.py:94: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <asyncio.unix_events._UnixDefaultEventLoopPolicy object at 0x7f07326b2bb0>

    def get_event_loop(self):
        """Get the event loop for the current context.
    
        Returns an instance of EventLoop or raises an exception.
        """
        if (self._local._loop is None and
                not self._local._set_called and
                isinstance(threading.current_thread(), threading._MainThread)):
            self.set_event_loop(self.new_event_loop())
    
        if self._local._loop is None:
>           raise RuntimeError('There is no current event loop in thread %r.'
                               % threading.current_thread().name)
E           RuntimeError: There is no current event loop in thread 'MainThread'.

/usr/local/lib/python3.8/asyncio/events.py:639: RuntimeError
...

The error appears when I run:

python -m pytest tests/test_dates.py::test_async_ticker -vv -duration=6  

where the test_async_ticker is:

import asyncio

import pytest

@pytest.mark.asyncio
async def test_async_ticker():
    async with dates.AsyncTicker() as ticker:
        await asyncio.sleep(0.001)

    assert ticker.time_elapsed().total_seconds() > 0

and AsyncTicker:

class AsyncTicker:
    '''Measures time between entering and exiting `async with` block.'''
    def __init__(self):
        self._start = None
        self._end = None

    async def __aenter__(self, *args, **kwargs):
        self._start = current_utc_instant()
        return self

    async def __aexit__(self, *args, **kwargs):
        self._end = current_utc_instant()

    def time_elapsed(self):
        return self._end - self._start
@barend
Copy link

barend commented Apr 19, 2021

I have this exact same problem, and from the looks of it, I've been diagnosing it at the exact same time. I can make the problem occur both in the docker image and in a local virtualenv, and I can reliably toggle it off or on by pip installing pytest-asyncio versions 0.14.0 or 0.15.0.

@Tinche
Copy link
Member

Tinche commented Apr 19, 2021

Ah, must have been caused by the loop cleanup changes in 0.15.0. Can be fixed relatively easily, just need to understand what exactly is going on first.

@barend
Copy link

barend commented Apr 19, 2021

Thank you for the swift response!

@Tinche
Copy link
Member

Tinche commented Apr 19, 2021

I cannot repro this with this test (tried 3.8.9 and 3.9.2):

import asyncio

import pytest

class AsyncTicker:
    '''Measures time between entering and exiting `async with` block.'''
    def __init__(self):
        self._start = None
        self._end = None

    async def __aenter__(self, *args, **kwargs):
        self._start = 1
        return self

    async def __aexit__(self, *args, **kwargs):
        self._end = 2

    def time_elapsed(self):
        return self._end - self._start

@pytest.mark.asyncio
async def test_async_ticker():
    async with AsyncTicker() as ticker:
        await asyncio.sleep(0.001)

    assert True

So would appreciate a minimal repro example!

@barend
Copy link

barend commented Apr 19, 2021

I'm dealing with a client's proprietary code base and cannot easily extract a reproducible sample. The most exciting thing here afaict is an asyncio.gather of a bunch of network calls issued at the same time.

@Tinche
Copy link
Member

Tinche commented Apr 19, 2021

To me it looks like something in your codebase is making asyncio produce the event loop for the main thread and then setting it to None. Then when pytest-asyncio takes over the event loop management the error pops out. Any chance of something like this happening?

@Kruszylo
Copy link
Author

I have extracted the test, in the same docker image with necessary requirements it works without error, but when I run it in my project it fails. I'll investigate further to find out what is happening.

@stevepentland
Copy link

stevepentland commented Apr 19, 2021

I have a similar issue. So far I have noted that prior tests on code that calls asyncio.run(...) leaves the loop on main closed and self._local._set_called set to True. The first time this plugin tries to setup for the marked function, get_event_loop fails due to set having already been called by the prior call to run. I did not experience this previously using this combo however

Edit: subsequent tests using the decorator do still pass though, it is only the first time it is used after asyncio.run(...) was used elsewhere

Edit 2: Swapped back to 0.14.0 and the tests pass in the same run order & environment

@Kruszylo
Copy link
Author

I think I have a code that reproduces the error. You will need to write docker file:

Dockerfile:

FROM python:3.8 as base

RUN apt-get update

RUN python3 -m venv venv
RUN /bin/bash -c "source venv/bin/activate"

RUN pip3 install pytest
RUN pip3 install hypothesis==6.9.2
RUN pip3 install pytest-asyncio==0.15.0

RUN /bin/bash -c "source venv/bin/activate"

# fix stdout & stderr missing from `docker logs`
ENV PYTHONUNBUFFERED=1

COPY tests.py .
CMD ["python3", "-m", "pytest", "tmp.py"]

write python script for tests:

tests.py:

import datetime
import asyncio
import queue
import threading

import pytest


def current_utc_instant() -> datetime.datetime:
    '''Datetime representing current UTC instant, with time zone'''
    return datetime.datetime.now(datetime.timezone.utc)



def _run_in_fresh_loop(coro, result_queue):
    loop = asyncio.new_event_loop()
    asyncio.set_event_loop(loop)

    try:
        result = loop.run_until_complete(coro)
        msg = {'success': True,
               'result': result}
    except Exception as e:
        msg = {'success': False,
               'exception': e}

    loop.close()
    result_queue.put(msg)


def run_in_thread(coro):
    '''Workaround for running async coroutine from a synchronous context  inside other async code,
    like `async(sync(async ()))`.

    Runs the coroutine in a separate thread with new event loop and blocks until the coroutine is completed.
    '''
    result_queue = queue.Queue()
    th = threading.Thread(target=_run_in_fresh_loop, args=(coro, result_queue))
    th.start()
    th.join()

    msg = result_queue.get()

    if msg['success']:
        return msg['result']
    else:
        raise msg['exception']


async def _async_division(x, y):
    await asyncio.sleep(0.001)
    return x / y


async def _async_wrapper_fn(x, y):
    # do async stuff
    await asyncio.sleep(0.001)

    # call sync subroutine that triggers a coroutine in another thread
    result = run_in_thread(_async_division(x, y))

    # do async stuff
    await asyncio.sleep(0.001)

    return result


class TestRunInThread:
    # def test_with_no_loop_success(self):
    #     assert 2 == run_in_thread(_async_division(6, 3))

    # def test_no_loop_exception(self):
    #     with pytest.raises(ZeroDivisionError):
    #         run_in_thread(_async_division(1, 0))

    def test_already_present_loop_success(self):
        assert 2 == asyncio.run(_async_wrapper_fn(6, 3))

    # def test_already_present_loop_exception(self):
    #     with pytest.raises(ZeroDivisionError):
    #         asyncio.run(_async_wrapper_fn(1, 0))


class AsyncTicker:
    '''Measures time between entering and exiting `async with` block.'''
    def __init__(self):
        self._start = None
        self._end = None

    async def __aenter__(self, *args, **kwargs):
        self._start = current_utc_instant()
        return self

    async def __aexit__(self, *args, **kwargs):
        self._end = current_utc_instant()

    def time_elapsed(self):
        return self._end - self._start

@pytest.mark.asyncio
async def test_async_ticker():
    async with AsyncTicker() as ticker:
        await asyncio.sleep(0.001)

    assert ticker.time_elapsed().total_seconds() > 0

build the image:

docker build -f Dockerfile -t 'pytest-issue-209' .

and run:

docker run 'pytest-issue-209'

Output:

============================= test session starts ==============================
platform linux -- Python 3.8.9, pytest-6.2.3, py-1.10.0, pluggy-0.13.1
rootdir: /
plugins: asyncio-0.15.0, hypothesis-6.9.2
collected 2 items

tmp.py .E                                                                [100%]

==================================== ERRORS ====================================
_____________________ ERROR at setup of test_async_ticker ______________________

fixturedef = <FixtureDef argname='event_loop' scope='function' baseid=''>
request = <SubRequest 'event_loop' for <Function test_async_ticker>>

    @pytest.hookimpl(hookwrapper=True)
    def pytest_fixture_setup(fixturedef, request):
        """Adjust the event loop policy when an event loop is produced."""
        if fixturedef.argname == "event_loop":
            outcome = yield
            loop = outcome.get_result()
            policy = asyncio.get_event_loop_policy()
>           old_loop = policy.get_event_loop()

usr/local/lib/python3.8/site-packages/pytest_asyncio/plugin.py:94: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <asyncio.unix_events._UnixDefaultEventLoopPolicy object at 0x7eff64c52700>

    def get_event_loop(self):
        """Get the event loop for the current context.
    
        Returns an instance of EventLoop or raises an exception.
        """
        if (self._local._loop is None and
                not self._local._set_called and
                isinstance(threading.current_thread(), threading._MainThread)):
            self.set_event_loop(self.new_event_loop())
    
        if self._local._loop is None:
>           raise RuntimeError('There is no current event loop in thread %r.'
                               % threading.current_thread().name)
E           RuntimeError: There is no current event loop in thread 'MainThread'.

usr/local/lib/python3.8/asyncio/events.py:639: RuntimeError
=========================== short test summary info ============================
ERROR tmp.py::test_async_ticker - RuntimeError: There is no current event loo...
========================== 1 passed, 1 error in 0.10s ==========================

@Tinche
Copy link
Member

Tinche commented Apr 19, 2021

Could people from this thread try the latest commit on the master branch and report if it fixes it?

@escapewindow
Copy link

escapewindow commented Apr 20, 2021

It looks like 94c2560 results in tests hanging, without any error message.

[EDIT] Trying multiple times to see what's going on, and see if I can isolate the issue. Curious if anyone else is seeing similar issues.

[2nd EDIT] I'm now getting errors, Event loop is closed again, e.g.

tests/test_production.py::test_verify_production_cot[fenix production] Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x10fbb5790>
Traceback (most recent call last):
  File "/Users/asasaki/.pyenv/versions/3.8.0/lib/python3.8/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/Users/asasaki/.pyenv/versions/3.8.0/lib/python3.8/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/Users/asasaki/.pyenv/versions/3.8.0/lib/python3.8/asyncio/unix_events.py", line 536, in close
    self._close(None)
  File "/Users/asasaki/.pyenv/versions/3.8.0/lib/python3.8/asyncio/unix_events.py", line 560, in _close
    self._loop.call_soon(self._call_connection_lost, exc)
  File "/Users/asasaki/.pyenv/versions/3.8.0/lib/python3.8/asyncio/base_events.py", line 711, in call_soon
    self._check_closed()
  File "/Users/asasaki/.pyenv/versions/3.8.0/lib/python3.8/asyncio/base_events.py", line 504, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

This is largely in a complex test decorated with @pytest.mark.asyncio and @pytest.mark.parametrize, without an event_loop fixture, with many coroutines awaiting on other coroutines.

@adilkhash
Copy link

Could people from this thread try the latest commit on the master branch and report if it fixes it?

I can confirm that the error disappeared after the introduction of the exception handling.

@Kruszylo
Copy link
Author

Could people from this thread try the latest commit on the master branch and report if it fixes it?

I can confirm, the try clause fixes the problem.

@achimnol
Copy link

achimnol commented Apr 21, 2021

I also encountered the same issue since the 0.15 release and confirm that the latest main branch with exception handling fixes the problem, without changing my tests & fixtures.
Some of my fixtures also have been using asyncio.run() to initialize and finalize stuffs.

@Tinche
Copy link
Member

Tinche commented Apr 21, 2021

Ok, this will be going out soon as 0.15.1.

@barend
Copy link

barend commented Apr 21, 2021

Could people from this thread try the latest commit on the master branch and report if it fixes it?

Same as the others. The problem is fixed when I run against that version.

@Tinche
Copy link
Member

Tinche commented Apr 21, 2021

0.15.1 is out! Give it a test.

@escapewindow
Copy link

Still broken for me. I'll pin to <15.0.

@Tinche
Copy link
Member

Tinche commented Apr 22, 2021

@escapewindow feel free to open a different issue, I think yours is something else. A minimal repro would be nice

carltongibson added a commit to django/channels that referenced this issue Jul 11, 2021
Reverts 1945a9f.
Issue in 0.15.0 resolved in 0.15.1.
Refs #1682
Refs pytest-dev/pytest-asyncio#209
carltongibson added a commit to django/channels that referenced this issue Jul 11, 2021
Reverts 1945a9f.
Issue in 0.15.0 resolved in 0.15.1.
Refs #1682
Refs pytest-dev/pytest-asyncio#209
@seifertm
Copy link
Contributor

This issue is about pytest-asyncio-0.15.0 and there hasn't been any progress in this issue for almost a year. The following v0.15.1 release seemed to fix the problem for most of the participants of this discussion, as well as for the django/channels project.

A lot has happened since v0.15.0 and pytest-asyncio is now at v0.18.2. Please file a new bug, if you encounter any issues.

@escapewindow If you're still affected by a pytest-asyncio problem, I encourage you to try the latest version. Any feedback would be appreciated!

tmautone added a commit to tmautone/django-channels that referenced this issue Oct 25, 2024
Reverts 1945a9fc286fc0afda1e1371562a743fbe97ccb5.
Issue in 0.15.0 resolved in 0.15.1.
Refs #1682
Refs pytest-dev/pytest-asyncio#209
phillipchain added a commit to phillipchain/DjangoChannels that referenced this issue Nov 4, 2024
Reverts 1945a9fc286fc0afda1e1371562a743fbe97ccb5.
Issue in 0.15.0 resolved in 0.15.1.
Refs #1682
Refs pytest-dev/pytest-asyncio#209
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants