Closed GeoKafkias closed 6 months ago
Hi @GeoKafkias, I'm not sure given the information you provided this is an issue with Granian.
From the stack-trace you provided, it seems starlette is complaining about some ASGI response messages your application is returning, in fact if Granian had any complains about that you'll probably end up seeing some protocol exceptions raised by Granian code.
Does the same works with uvicorn? If so, I ask you to provide some more context on what the applications is doing on that specific request. Also, I wonder if without the middlewares you mentioned it works fine or not.
Hey @gi0baro,
Thanks for your response.
I forgot to mention that everything works fine when I am using unicorn. Also, I tested the case when I am not using middlewares at all where Granian works as expected but when I activate them I get the same error.
@GeoKafkias can you identify which Middleware raises the error? Like if you can activate them one by one it might be helpful identifying which one or which combination is producing the issue
Also, I'd love some advice from @Kludex on this :)
This is not a Granian issue, it's a Starlette one. Feel free to close it. 👍
This is not a Granian issue, it's a Starlette one. Feel free to close it. 👍
@Kludex thank you for the quick reply. Do you have any tracked issue/discussion on Starlette repo I can mention here before closing this?
No, we don't have an issue yet. Someone needs to create a discussion, and provide some MRE yet.
What is probably happening is that the message is "http.disconnect"
instead of "http.response.body"
, and we are not considering it can be disconnect (that's my guess).
@Kludex thank you for the explanation. I think that makes sense, it probably happens with Granian only 'cause the concurrency flow might be a bit different from uvicorn in dealing with recv/send messages.
@GeoKafkias please open a discussion on Starlette repo as @Kludex suggested, you can mention this issue as a starting point. I'm closing this, feel free to mention me in Starlette repo if you need anything from my side.
(I think it does happen with Uvicorn as well... Not 100% sure, but I saw this issue being mentioned elsewhere...)
Hey Both,
Thanks for your help.
Uvicorn is functioning as expected; I am confident about this (100% sure). However, I'm encountering issues when integrating granian—regardless of the various middleware combinations I've experimented with, errors persist exclusively in the presence of granian for both mentioned middelwares or one by one.
The following code can reproduce this problem. I don't care whether it is caused by Starlette or Granian, but if this problem persists, I can only continue to use Uvicorn or Gunicorn and cannot migrate to Granian. I did not encounter this problem when using Uvicorn and Gunicorn
from fastapi import FastAPI
from collections.abc import Callable
from typing import Any
from fastapi import Request
from starlette.middleware.base import BaseHTTPMiddleware
class AccessMiddleware(BaseHTTPMiddleware):
"""
记录请求日志
"""
async def dispatch(self, request: Request, call_next: Callable[[Any], Any]) -> Any:
# start_time = datetime.now()
response = await call_next(request)
# end_time = datetime.now()
# 用时 单位秒
# use_time = (end_time - start_time).total_seconds()
# logger.info(
# f"{response.headers.get('X-Request-ID')} {response.status_code} "
# f"{request.client.host if request.client else ''} "
# f"{request.method} {request.url} {use_time}"
# )
return response
app = FastAPI()
app.add_middleware(AccessMiddleware)
@app.get("/")
def hello():
return "hello"
granian --interface asgi 1:app --host=0.0.0.0 --port=9000 --workers=2
[INFO] Starting granian (main PID: 81160)
[INFO] Listening at: 0.0.0.0:9000
[INFO] Spawning worker-1 with pid: 81162
[INFO] Spawning worker-2 with pid: 81163
[INFO] Started worker-1
[INFO] Started worker-1 runtime-1
[INFO] Started worker-2
[INFO] Started worker-2 runtime-1
[ERROR] Application callable raised an exception
Traceback (most recent call last):
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/granian/_futures.py", line 4, in future_watcher
await inner(watcher.scope, watcher.proto)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/applications.py", line 116, in __call__
await self.middleware_stack(scope, receive, send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/middleware/base.py", line 192, in __call__
await response(scope, wrapped_receive, send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/responses.py", line 259, in __call__
await wrap(partial(self.listen_for_disconnect, receive))
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/responses.py", line 255, in wrap
await func()
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/responses.py", line 232, in listen_for_disconnect
message = await receive()
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/middleware/base.py", line 52, in wrapped_receive
msg = await self.receive()
CancelledError: Future cancelled.
[ERROR] Application callable raised an exception
Traceback (most recent call last):
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/granian/_futures.py", line 4, in future_watcher
await inner(watcher.scope, watcher.proto)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/applications.py", line 116, in __call__
await self.middleware_stack(scope, receive, send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/middleware/base.py", line 192, in __call__
await response(scope, wrapped_receive, send)
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/responses.py", line 259, in __call__
await wrap(partial(self.listen_for_disconnect, receive))
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/responses.py", line 255, in wrap
await func()
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/responses.py", line 232, in listen_for_disconnect
message = await receive()
File "/Users/wangf/Desktop/work_shuan/web/后端/GaoKao/.venv/lib/python3.10/site-packages/starlette/middleware/base.py", line 52, in wrapped_receive
msg = await self.receive()
CancelledError: Future cancelled.
@wf1314 @GeoKafkias I gonna spend some time reproducing this locally and do some debugging later today
@wf1314 FYI I can reproduce your issue locally with Python 3.10. Interestingly, it doesn't happen with Python 3.11. Will report more updates as I dig more into this.
@wf1314 it is also worth noting, even if Granian is reporting that CancelledError
message, I still get responses correctly even on Python 3.10
(Oi, sorry. I was wrong, and it only happens with granian? Just to check)
Update on @wf1314 CancelledError
issue: I think this is due to either anyio
or asyncio
implementations on Python < 3.11
The involved Starlette code is https://github.com/encode/starlette/blob/0.36.3/starlette/responses.py#L257-L264
async with anyio.create_task_group() as task_group:
async def wrap(func: typing.Callable[[], typing.Awaitable[None]]) -> None:
await func()
task_group.cancel_scope.cancel()
task_group.start_soon(wrap, partial(self.stream_response, send))
await wrap(partial(self.listen_for_disconnect, receive))
Now, I don't exactly know what's wrong, but clearly something is different in handling cancellation with anyio
taskgroups (this https://github.com/agronholm/anyio/issues/685 might seem related).
Below are the tests (some debugging info added on Granian, the HERE was added before this Starlette line https://github.com/encode/starlette/blob/0.36.3/starlette/middleware/base.py#L52):
(.venv) giovanni@DK67H9J40Y ~/Downloads/starlette-granian-test ❯ granian --interface asgi app:app
[INFO] Starting granian (main PID: 76984)
[INFO] Listening at: 127.0.0.1:8000
[INFO] Spawning worker-1 with pid: 76986
[INFO] Started worker-1
[INFO] Started worker-1 runtime-1
mid bef
mid aft
recv called
send called
recv flow_rx_exhausted set
send called
HERE
recv called
recv flow_rx_exhausted
send called
send bef notify disconnect waiter
send aft notify disconnect waiter
cancel called with message Some("Cancelled by cancel scope 103a5f490")
recv wait for holder
recv holder completed
cancel called with message Some("Cancelled by cancel scope 103a5f490")
[ERROR] Application callable raised an exception
Traceback (most recent call last):
File "/Users/giovanni/Development/Emmett/granian/granian/_futures.py", line 4, in future_watcher
await inner(watcher.scope, watcher.proto)
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/middleware/base.py", line 194, in __call__
await response(scope, wrapped_receive, send)
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/responses.py", line 264, in __call__
await wrap(partial(self.listen_for_disconnect, receive))
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/responses.py", line 260, in wrap
await func()
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/responses.py", line 237, in listen_for_disconnect
message = await receive()
File "/Users/giovanni/Downloads/starlette-granian-test/.venv/lib/python3.10/site-packages/starlette/middleware/base.py", line 53, in wrapped_receive
msg = await self.receive()
CancelledError: Future cancelled.
(.venv311) giovanni@DK67H9J40Y ~/Downloads/starlette-granian-test ❯ granian --interface asgi app:app
[INFO] Starting granian (main PID: 78215)
[INFO] Listening at: 127.0.0.1:8000
[INFO] Spawning worker-1 with pid: 78217
[INFO] Started worker-1
[INFO] Started worker-1 runtime-1
mid bef
mid aft
recv called
send called
send called
recv flow_rx_exhausted set
HERE
recv called
recv flow_rx_exhausted
send called
send bef notify disconnect waiter
send aft notify disconnect waiter
cancel called with message Some("Cancelled by cancel scope 107ebdc50")
cancel called with message Some("Cancelled by cancel scope 107ebdc50")
(.venv312) giovanni@DK67H9J40Y ~/Downloads/starlette-granian-test ❯ granian --interface asgi app:app
[INFO] Starting granian (main PID: 78007)
[INFO] Listening at: 127.0.0.1:8000
[INFO] Spawning worker-1 with pid: 78009
[INFO] Started worker-1
[INFO] Started worker-1 runtime-1
mid bef
mid aft
recv called
send called
recv flow_rx_exhausted set
send called
HERE
recv called
recv flow_rx_exhausted
send called
send bef notify disconnect waiter
send aft notify disconnect waiter
cancel called with message Some("Cancelled by cancel scope 106049760")
cancel called with message Some("Cancelled by cancel scope 106049760")
So my position on this @wf1314 is that there's nothing Granian can do to solve it. Also 'cause there's nothing changing between Python versions in Granian asyncio
related code, all the interfaces behave in the same way. IMHO possible solutions for you are:
Also, under my perspective, this happens under Granian and not Uvicorn just because Granian is effectively more concurrent (async send and receive are handled in Rust separated threads, and not 1 by 1 from the single thread of the Python event loop), and thus any code that coincidentally was written taking into account consequentiality in tasks/steps happening in Python will fail in Granian.
Regarding the original issue reported by @GeoKafkias, I'll perform some specific debugging later to actually get the culprit.
@GeoKafkias I can't reproduce your issue locally. I suspect it might actually related to Windows. Do you have any chance to test the same code with a different platform?
@wf1314 just another consideration, you might also want to wait for Granian 1.2 that will introduce some major refactors due to PyO3 API changes and check if anything changes on Python 3.10 with your stack. But there's no ETA and no assurance it will do make any difference.
@gi0baro Thank you very much for your investigation of this problem and the results and solutions you provided. I think this will guide other people who encounter the same problems to keep their trust and expectation in Granian.
Hey @gi0baro,
I don't know if this info plays any role but I forgot to mention that the response class of the requests is HTMLResponse. I still have the issue in the Ubuntu environment. Python version for Windows is 3.11.5 and for Ubuntu 3.11.4 and I am using poetry for python packaging and dependency management.
Here is my code:
from functools import partial
from fastapi import FastAPI
from fastapi.middleware.gzip import GZipMiddleware
from fastapi.responses import JSONResponse
from fastapi.staticfiles import StaticFiles
from loguru import logger
from slowapi import _rate_limit_exceeded_handler
from slowapi.errors import RateLimitExceeded
from slowapi.middleware import SlowAPIMiddleware
from app.config.api_lifespan import lifespan
from app.config.app_settings import fastapi_settings
from app.config.limiter import limiter
from app.config.paths import app_paths
from app.routers.website import web_router
def deploy_app(
logger: logger, # type: ignore
) -> FastAPI:
lifespan_with_args = partial(
lifespan,
logger=logger,
)
app = FastAPI(
**fastapi_settings.fastapi_kwargs,
lifespan=lifespan_with_args,
)
app.state.limiter = limiter
app.add_exception_handler(RateLimitExceeded, _rate_limit_exceeded_handler)
app.mount(
"/static",
StaticFiles(directory=app_paths.STATIC_DIR.as_posix()),
name="static",
)
app.mount(
"/assets",
StaticFiles(directory=app_paths.ASSETS_DIR.as_posix()),
name="assets",
)
app.mount(
"/htmx",
StaticFiles(directory=app_paths.HTMX_DIR.as_posix()),
name="htmx",
)
app.mount(
"/alpine",
StaticFiles(directory=app_paths.ALPINE_DIR.as_posix()),
name="alpine",
)
app.add_middleware(middleware_class=GZipMiddleware)
app.add_middleware(middleware_class=SlowAPIMiddleware)
app.add_api_route(
path="/health",
endpoint=lambda: {"status": "ok"},
methods=["GET"],
name="health",
include_in_schema=True,
response_class=JSONResponse,
)
app.include_router(router=web_router)
return app
logger.add(
app_paths.BASE_DIR / "logs/app.log",
rotation="1 MB",
retention="10 days",
level="INFO",
)
app = deploy_app(logger=logger)
and the traceback:
[ERROR] Application callable raised an exception
Traceback (most recent call last):
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/granian/_futures.py", line 4, in future_watcher
await inner(watcher.scope, watcher.proto)
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/middleware/errors.py", line 186, in __call__
raise exc
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/middleware/base.py", line 189, in __call__
with collapse_excgroups():
File "/root/miniconda3/lib/python3.11/contextlib.py", line 155, in __exit__
self.gen.throw(typ, value, traceback)
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/_utils.py", line 93, in collapse_excgroups
raise exc
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/middleware/base.py", line 191, in __call__
response = await self.dispatch_func(request, call_next)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/slowapi/middleware.py", line 128, in dispatch
return await call_next(request)
^^^^^^^^^^^^^^^^^^^^^^^^
File "/root/.cache/pypoetry/virtualenvs/website-v-for-vets-wOrdpAQ5-py3.11/lib/python3.11/site-packages/starlette/middleware/base.py", line 166, in call_next
raise RuntimeError("No response returned.")
RuntimeError: No response returned.
Let me know if I can do something else. Thanks for your time.
@GeoKafkias @wf1314 can you both please try again with 1.2.0 and report any updates on this?
Hey @gi0baro ,
I updated and tested the newest version (1.2.0), but I still get some errors. From the previous version, I just got a new error in the terminal; see the following:
2024-03-23 18:28:26,546:ERROR - Exception in callback <builtins.PyFutureResultSetter object at 0x000002687AC46020>(<built-in met...002687CA94790>, {'type': 'http.disconnect'})
handle: <Handle <builtins.PyFutureResultSetter object at 0x000002687AC46020>(<built-in met...002687CA94790>, {'type': 'http.disconnect'})>
Traceback (most recent call last):
File "C:\Users\Geo\AppData\Local\Programs\Python\Python311\Lib\asyncio\events.py", line 80, in _run
self._context.run(self._callback, *self._args)
asyncio.exceptions.InvalidStateError: invalid state
and here is the old error:
Traceback (most recent call last):
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\granian\_futures.py", line 4, in future_watcher
await inner(watcher.scope, watcher.proto)
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\fastapi\applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\middleware\errors.py", line 186, in __call__
raise exc
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\middleware\errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\middleware\base.py", line 189, in __call__
with collapse_excgroups():
File "C:\Users\Geo\AppData\Local\Programs\Python\Python311\Lib\contextlib.py", line 155, in __exit__
self.gen.throw(typ, value, traceback)
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\_utils.py", line 93, in collapse_excgroups
raise exc
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\middleware\base.py", line 191, in __call__
response = await self.dispatch_func(request, call_next)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\slowapi\middleware.py", line 128, in dispatch
return await call_next(request)
^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\Geo\AppData\Local\pypoetry\Cache\virtualenvs\website-v-for-vets-QDVzixt4-py3.11\Lib\site-packages\starlette\middleware\base.py", line 166, in call_next
raise RuntimeError("No response returned.")
RuntimeError: No response returned.
@GeoKafkias thank you for the update. Are you also able to check the same on Linux/Mac?
Hello @gi0baro,
I haven't had a chance to review version 1.2 in the Linux environment yet. I plan to do so later this week when I have some free time.
Closing this due to changes in 1.3 Feel free to open up a new issue in case you still experience problems.
Hey,
Firstly, I would like to express my gratitude for developing this exceptional package and your effort in it. I am fairly new to this area, but I am considering leveraging Granian's power for my FastAPI project. A little background: I am integrating various middleware (SlowAPIMiddelware & GZipMiddleware) into my FastAPI application, but I have encountered an issue that I hope to get some guidance on.
When running my FastAPI with Granian, I am facing an "AssertionError" linked to middleware processing when the application asserts the message type as "http.response.body". Check Error Traceback .
Here are the dependencies of my environment:
Thanks in advance!
Funding