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

test_custom_middleware[trio] fails on 1-core-VM #1255

Closed
1 of 2 tasks
bmwiedemann opened this issue Jul 29, 2021 · 11 comments · Fixed by #1262
Closed
1 of 2 tasks

test_custom_middleware[trio] fails on 1-core-VM #1255

bmwiedemann opened this issue Jul 29, 2021 · 11 comments · Fixed by #1262
Labels
bug Something isn't working clean up Refinement to existing functionality

Comments

@bmwiedemann
Copy link

Checklist

  • The bug is reproducible against the latest release and/or master.
  • There are no similar issues or pull requests to fix it yet.

Describe the bug

While working on reproducible builds for openSUSE, I found that our python-starlette-0.16.0 package failed 1 test when running in a 1-core-VM (usually this happens due to differences in scheduling/timing)

To reproduce

maybe run tests as taskset 1 pytest

or on Debian or openSUSE run

osc checkout openSUSE:Factory/python-starlette && cd $_
osc build --vm-type=kvm --noservice --clean -j1 standard

Expected behavior

tests should pass

Actual behavior

test_custom_middleware[trio] fails

Debugging material

 =================================== FAILURES ===================================
 _________________________ test_custom_middleware[trio] _________________________
 
 test_client_factory = functools.partial(<class 'starlette.testclient.TestClient'>, backend='trio', backend_options={})
 
     def test_custom_middleware(test_client_factory):
         client = test_client_factory(app)
         response = client.get("/")
         assert response.headers["Custom-Header"] == "Example"
     
         with pytest.raises(Exception):
 >           response = client.get("/exc")
 
 tests/middleware/test_base.py:56: 
 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 /usr/lib/python3.9/site-packages/requests/sessions.py:555: in get
     return self.request('GET', url, **kwargs)
 starlette/testclient.py:468: in request
     return super().request(
 /usr/lib/python3.9/site-packages/requests/sessions.py:542: in request
     resp = self.send(prep, **send_kwargs)
 /usr/lib/python3.9/site-packages/requests/sessions.py:655: in send
     r = adapter.send(request, **kwargs)
 starlette/testclient.py:266: in send
     raise exc
 starlette/testclient.py:263: in send
     portal.call(self.app, scope, receive, send)
 /usr/lib/python3.9/site-packages/anyio/from_thread.py:229: in call
     return self.start_task_soon(func, *args).result()
 /usr/lib64/python3.9/concurrent/futures/_base.py:445: in result
     return self.__get_result()
 /usr/lib64/python3.9/concurrent/futures/_base.py:390: in __get_result
     raise self._exception
 /usr/lib/python3.9/site-packages/anyio/from_thread.py:176: in _call_func
     retval = await retval
 starlette/applications.py:112: in __call__
     await self.middleware_stack(scope, receive, send)
 starlette/middleware/errors.py:159: in __call__
     await self.app(scope, receive, _send)
 starlette/middleware/base.py:57: in __call__
     task_group.cancel_scope.cancel()
 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 
 self = <anyio._backends._trio.TaskGroup object at 0x7f1d7c50a5b0>
 exc_type = <class 'RuntimeError'>
 exc_val = RuntimeError('No response returned.')
 exc_tb = <traceback object at 0x7f1d7c5294c0>
 
     async def __aexit__(self, exc_type: Optional[Type[BaseException]],
                         exc_val: Optional[BaseException],
                         exc_tb: Optional[TracebackType]) -> Optional[bool]:
         try:
             return await self._nursery_manager.__aexit__(exc_type, exc_val, exc_tb)
         except trio.MultiError as exc:
 >           raise ExceptionGroup(exc.exceptions) from None
 E           anyio._backends._trio.ExceptionGroup: 2 exceptions were raised in the task group:
 E           ----------------------------
 E           Traceback (most recent call last):
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/middleware/base.py", line 30, in coro
 E               await self.app(scope, request.receive, send_stream.send)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/exceptions.py", line 82, in __call__
 E               raise exc
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/exceptions.py", line 71, in __call__
 E               await self.app(scope, receive, sender)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/routing.py", line 656, in __call__
 E               await route.handle(scope, receive, send)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/routing.py", line 259, in handle
 E               await self.app(scope, receive, send)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/routing.py", line 63, in app
 E               response = await run_in_threadpool(func, request)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/concurrency.py", line 39, in run_in_threadpool
 E               return await anyio.to_thread.run_sync(func, *args)
 E             File "/usr/lib/python3.9/site-packages/anyio/to_thread.py", line 28, in run_sync
 E               return await get_asynclib().run_sync_in_worker_thread(func, *args, cancellable=cancellable,
 E             File "/usr/lib/python3.9/site-packages/anyio/_backends/_trio.py", line 170, in run_sync_in_worker_thread
 E               return await run_sync(wrapper, cancellable=cancellable, limiter=limiter)
 E             File "/usr/lib/python3.9/site-packages/trio/_threads.py", line 205, in to_thread_run_sync
 E               return await trio.lowlevel.wait_task_rescheduled(abort)
 E             File "/usr/lib/python3.9/site-packages/trio/_core/_traps.py", line 166, in wait_task_rescheduled
 E               return (await _async_yield(WaitTaskRescheduled(abort_func))).unwrap()
 E             File "/usr/lib/python3.9/site-packages/outcome/_sync.py", line 111, in unwrap
 E               raise captured_error
 E             File "/usr/lib/python3.9/site-packages/trio/_threads.py", line 155, in do_release_then_return_result
 E               return result.unwrap()
 E             File "/usr/lib/python3.9/site-packages/outcome/_sync.py", line 111, in unwrap
 E               raise captured_error
 E             File "/usr/lib/python3.9/site-packages/trio/_threads.py", line 168, in worker_fn
 E               ret = sync_fn(*args)
 E             File "/usr/lib/python3.9/site-packages/anyio/_backends/_trio.py", line 168, in wrapper
 E               return func(*args)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/tests/middleware/test_base.py", line 28, in exc
 E               raise Exception()
 E           Exception
 E           ----------------------------
 E           Traceback (most recent call last):
 E             File "/usr/lib/python3.9/site-packages/anyio/streams/memory.py", line 78, in receive
 E               return self.receive_nowait()
 E             File "/usr/lib/python3.9/site-packages/anyio/streams/memory.py", line 73, in receive_nowait
 E               raise WouldBlock
 E           anyio.WouldBlock
 E           
 E           During handling of the above exception, another exception occurred:
 E           
 E           Traceback (most recent call last):
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/middleware/base.py", line 35, in call_next
 E               message = await recv_stream.receive()
 E             File "/usr/lib/python3.9/site-packages/anyio/streams/memory.py", line 98, in receive
 E               raise EndOfStream
 E           anyio.EndOfStream
 E           
 E           During handling of the above exception, another exception occurred:
 E           
 E           Traceback (most recent call last):
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/middleware/base.py", line 55, in __call__
 E               response = await self.dispatch_func(request, call_next)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/tests/middleware/test_base.py", line 12, in dispatch
 E               response = await call_next(request)
 E             File "/home/abuild/rpmbuild/BUILD/starlette-0.16.0/starlette/middleware/base.py", line 37, in call_next
 E               raise RuntimeError("No response returned.")
 E           RuntimeError: No response returned.
 
 /usr/lib/python3.9/site-packages/anyio/_backends/_trio.py:141: ExceptionGroup
 =========================== short test summary info ============================
 SKIPPED [3] tests/conftest.py:14: Trio not supported (yet!)
 =================== 1 failed, 464 passed, 3 skipped in 4.95s ===================

Environment

  • OS: Linux = openSUSE Tumbleweed 20210726
  • Python version: 3.9
  • Starlette version: 0.16.0

Additional context

This bug was found while working on reproducible builds for openSUSE.

@florimondmanca
Copy link
Member

florimondmanca commented Aug 11, 2021

@bmwiedemann I am getting the same issue on an asyncio setup as soon as any custom middleware is combined with a view that raises an exception, as in the following repro case:

import httpx
import asyncio
from starlette.applications import Starlette
from starlette.routing import Route
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.middleware import Middleware


async def error(request):
    raise RuntimeError("oops")


class MyMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        return await call_next(request)


app = Starlette(routes=[Route("/error", error)], middleware=[Middleware(MyMiddleware)])


async def main():
    async with httpx.AsyncClient(app=app) as client:
        _ = await client.get("http://testserver/error")


asyncio.run(main())
$ python example.py
Traceback (most recent call last):
  File "/Users/florimond/Desktop/test.py", line 26, in <module>
    asyncio.run(main())
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/Users/florimond/Desktop/test.py", line 23, in main
    _ = await client.get("http://testserver/error")
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_client.py", line 1722, in get
    return await self.request(
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_client.py", line 1481, in request
    response = await self.send(
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_client.py", line 1568, in send
    response = await self._send_handling_auth(
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_client.py", line 1604, in _send_handling_auth
    response = await self._send_handling_redirects(
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_client.py", line 1640, in _send_handling_redirects
    response = await self._send_single_request(request, timeout)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_client.py", line 1681, in _send_single_request
    ) = await transport.handle_async_request(
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/httpx/_transports/asgi.py", line 157, in handle_async_request
    await self.app(scope, receive, send)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/applications.py", line 112, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/middleware/errors.py", line 159, in __call__
    await self.app(scope, receive, _send)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/middleware/base.py", line 57, in __call__
    task_group.cancel_scope.cancel()
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/anyio/_backends/_asyncio.py", line 562, in __aexit__
    raise ExceptionGroup(exceptions)
anyio._backends._asyncio.ExceptionGroup: 2 exceptions were raised in the task group:
----------------------------
Traceback (most recent call last):
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/middleware/base.py", line 35, in call_next
    message = await recv_stream.receive()
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/anyio/streams/memory.py", line 79, in receive
    return self.receive_nowait()
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/anyio/streams/memory.py", line 72, in receive_nowait
    raise EndOfStream
anyio.EndOfStream

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/middleware/base.py", line 55, in __call__
    response = await self.dispatch_func(request, call_next)
  File "/Users/florimond/Desktop/test.py", line 15, in dispatch
    return await call_next(request)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/middleware/base.py", line 37, in call_next
    raise RuntimeError("No response returned.")
RuntimeError: No response returned.
----------------------------
Traceback (most recent call last):
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/middleware/base.py", line 30, in coro
    await self.app(scope, request.receive, send_stream.send)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/exceptions.py", line 82, in __call__
    raise exc
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/exceptions.py", line 71, in __call__
    await self.app(scope, receive, sender)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/routing.py", line 656, in __call__
    await route.handle(scope, receive, send)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/routing.py", line 259, in handle
    await self.app(scope, receive, send)
  File "/Users/florimond/.pyenv/versions/3.9.0/lib/python3.9/site-packages/starlette/routing.py", line 61, in app
    response = await func(request)
  File "/Users/florimond/Desktop/test.py", line 10, in error
    raise RuntimeError("oops")
RuntimeError: oops

This seems to have been introduced via #1157 (cc @uSpike) which switched the behavior of detecting "response not received". Switching back to eg starlette==0.15.* makes this go away.

The expectation here would be that RuntimeError: oops would be surfacing as the sole exception, yet now anyio now correctly wraps the 2 independent exceptions that are occurring: the RuntimeError("No response received") (which might need tweaking?), and the one the view triggered.

@jerber
Copy link

jerber commented Nov 1, 2021

@florimondmanca this error is happening to me too, is there any solution you'd recommend if we don't want to downgrade Starlette?

@Kludex
Copy link
Sponsor Member

Kludex commented Nov 1, 2021

The fix will be on Starlette 0.17.0.

@jerber
Copy link

jerber commented Nov 1, 2021

@Kludex awesome, do you know when that will be?

@Kludex
Copy link
Sponsor Member

Kludex commented Nov 2, 2021

Yep, whenever another member approves #1324

@ashkan-hadadi
Copy link

@kalzoo
Copy link

kalzoo commented Mar 11, 2022

Indeed, have been seeing this persistently even since an upgrade to 0.17.1:

File \".../lib/python3.7/site-packages/anyio/streams/memory.py\", line 81, in receive
    return self.receive_nowait()
  File \".../lib/python3.7/site-packages/anyio/streams/memory.py\", line 76, in receive_nowait
    raise WouldBlock
anyio.WouldBlock

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File \".../lib/python3.7/site-packages/starlette/middleware/base.py\", line 41, in call_next
    message = await recv_stream.receive()
  File \".../lib/python3.7/site-packages/anyio/streams/memory.py\", line 101, in receive
    raise EndOfStream
anyio.EndOfStream

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File \"...", line 324, in dispatch
    response = await call_next(request)
  File \".../lib/python3.7/site-packages/starlette/middleware/base.py\", line 45, in call_next
    raise RuntimeError(\"No response returned.\")

There's no pattern I can discern after a few hours of trying to reproduce. Happens on all request routes and with both short and long request durations. This service is hosted behind an AWS ALB; I wouldn't expect client-side issues there (such as disconnections). End users are seeing 503's when this occurs, so it's not like they're disconnecting early. We're using FastAPI on top of it, with custom exception handling middleware and also other middleware.

Tried to reproduce with an always-failing middleware but that sends a response correctly.

The only suggestions I've seen seem to be downgrading starlette; I can give that a shot. We've been running this service for at least 2 years now; this only started occurring a couple months ago, intermittently.

@jaredtkatz
Copy link

@kalzoo any success with downgrading starlette?

@freis
Copy link

freis commented Apr 26, 2022

This is still happening in 0.17.1

@flaudarin-365talents
Copy link

I could not find any other solution than to downgrade fastapi in order to get read of anyio as dependency of starlette.

fastapi 0.68.2
`-- starlette 0.14.2

Obviously, things are back to normal. I still can't figure out what's the root cause behind this exception anyio.WouldBlock raised from module anyio.streams.memory but I definitely have to. I cannot be stuck with fastapi 0.68.2 forever.

@Kludex
Copy link
Sponsor Member

Kludex commented Apr 27, 2022

The original issue here was solved. Please create a discussion with a showcase of when the new potential issue happens.

I'll lock this, so we can have things in the right place, and we don't mislead future users checking this issue. Messages here will not make any difference as, again, the original issue was solved.

@encode encode locked as resolved and limited conversation to collaborators Apr 27, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working clean up Refinement to existing functionality
Projects
None yet
Development

Successfully merging a pull request may close this issue.

9 participants