nginx
Running FastAPI app and getting a Starlette error
Discussed in https://github.com/nginx/unit/discussions/1100
Originally posted by bunny-therapist January 29, 2024
I am running a FastAPI app using nginx unit, and using a python script to send multiple sequential (wait for response before sending next) requests to it with the "requests" library. When I reuse the same requests.Session object for all the requests, so that requests.Session.close is not called, then I get intermittent crashes in the application and thus status 500 back.
Traceback (most recent call last):
File "<path>/venv310/lib/python3.10/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "<path>/venv310/lib/python3.10/site-packages/starlette/applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/errors.py", line 186, in __call__
raise exc
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 189, in __call__
with collapse_excgroups():
File "/usr/lib/python3.10/contextlib.py", line 153, in __exit__
self.gen.throw(typ, value, traceback)
File "<path>/venv310/lib/python3.10/site-packages/starlette/_utils.py", line 91, in collapse_excgroups
raise exc
File "<path>/venv310/lib/python3.10/site-packages/starlette/responses.py", line 257, in wrap
await func()
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 217, in stream_response
return await super().stream_response(send)
File "<path>/venv310/lib/python3.10/site-packages/starlette/responses.py", line 246, in stream_response
async for chunk in self.body_iterator:
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 181, in body_stream
raise app_exc
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 151, in coro
await self.app(scope, receive_or_disconnect, send_no_error)
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 189, in __call__
with collapse_excgroups():
File "/usr/lib/python3.10/contextlib.py", line 153, in __exit__
self.gen.throw(typ, value, traceback)
File "<path>/venv310/lib/python3.10/site-packages/starlette/_utils.py", line 91, in collapse_excgroups
raise exc
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 128, in receive_or_disconnect
message = await wrap(wrapped_receive)
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 123, in wrap
result = await func()
File "<path>/venv310/lib/python3.10/site-packages/starlette/middleware/base.py", line 56, in wrapped_receive
raise RuntimeError(f"Unexpected message received: {msg['type']}")
RuntimeError: Unexpected message received: http.request
The error is coming from this line: https://github.com/encode/starlette/blob/master/starlette/middleware/base.py#L56 which appears to be starlette waiting for a client disconnect but instead getting the next request. (No idea why starlette wants the request to be closed instead of allowing it to be reused for the next request, but maybe there is something I am not aware of.)
I would (and will) ask about this in the starlette github, but I am posting here because I did not encounter this issue when running my FastAPI app with uvicorn, it only happens with nginx unit, so at a minimum, it appears that something is different here which is causing problems, and this is probably something that should be identified.
I was really happy when I discovered nginx unit; this issue is currently the only thing that is preventing me from adopting it.
Thanks to @bunny-therapist for providing a reproducer, summarised below...
gh1100.py
from fastapi import FastAPI
from fastapi.responses import JSONResponse
from pydantic import BaseModel
from fastapi.responses import Response
class RequestBody(BaseModel):
number: int
app = FastAPI()
@app.middleware("http")
async def my_middleware(request, call_next):
response = await call_next(request)
return response
@app.post("/predict")
async def post_predict(body: RequestBody):
return JSONResponse(content={"got": body.number})
@app.get("/data")
async def get_data():
return Response()
gh1100.json
{
"listeners": {
"[::1]:8080": {
"pass": "applications/fastapi"
}
},
"applications": {
"fastapi": {
"type": "python",
"path": "/home/andrew/src/python",
"module": "gh1100",
"callable": "app",
"protocol": "asgi"
}
}
}
gh1100-client.py
#!/usr/bin/python
import requests
N = 2
with requests.Session() as session:
for _ in range(N):
r = session.post("http://localhost:8080/predict", json={"number": 1})
r.raise_for_status()
Running it produces the following in the unit log
2024/01/30 17:01:14 [error] 43868#43868 [unit] #17: Python failed to call 'future.result()'
+ Exception Group Traceback (most recent call last):
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 192, in __call__
| await response(scope, wrapped_receive, send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 254, in __call__
| async with anyio.create_task_group() as task_group:
| File "/home/andrew/.local/lib/python3.12/site-packages/anyio/_backends/_asyncio.py", line 678, in __aexit__
| raise BaseExceptionGroup(
| ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
+-+---------------- 1 ----------------
| Traceback (most recent call last):
| File "/home/andrew/.local/lib/python3.12/site-packages/fastapi/applications.py", line 1054, in __call__
| await super().__call__(scope, receive, send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/applications.py", line 123, in __call__
| await self.middleware_stack(scope, receive, send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/errors.py", line 186, in __call__
| raise exc
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/errors.py", line 164, in __call__
| await self.app(scope, receive, _send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 189, in __call__
| with collapse_excgroups():
| File "/usr/lib64/python3.12/contextlib.py", line 158, in __exit__
| self.gen.throw(value)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/_utils.py", line 91, in collapse_excgroups
| raise exc
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 261, in __call__
| await wrap(partial(self.listen_for_disconnect, receive))
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 257, in wrap
| await func()
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 234, in listen_for_disconnect
| message = await receive()
| ^^^^^^^^^^^^^^^
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 56, in wrapped_receive
| raise RuntimeError(f"Unexpected message received: {msg['type']}")
| RuntimeError: Unexpected message received: http.request
+------------------------------------
During handling of the above exception, another exception occurred:
+ Exception Group Traceback (most recent call last):
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/_utils.py", line 85, in collapse_excgroups
| yield
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 190, in __call__
| async with anyio.create_task_group() as task_group:
| File "/home/andrew/.local/lib/python3.12/site-packages/anyio/_backends/_asyncio.py", line 678, in __aexit__
| raise BaseExceptionGroup(
| ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
+-+---------------- 1 ----------------
| Exception Group Traceback (most recent call last):
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 192, in __call__
| await response(scope, wrapped_receive, send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 254, in __call__
| async with anyio.create_task_group() as task_group:
| File "/home/andrew/.local/lib/python3.12/site-packages/anyio/_backends/_asyncio.py", line 678, in __aexit__
| raise BaseExceptionGroup(
| ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
+-+---------------- 1 ----------------
| Traceback (most recent call last):
| File "/home/andrew/.local/lib/python3.12/site-packages/fastapi/applications.py", line 1054, in __call__
| await super().__call__(scope, receive, send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/applications.py", line 123, in __call__
| await self.middleware_stack(scope, receive, send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/errors.py", line 186, in __call__
| raise exc
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/errors.py", line 164, in __call__
| await self.app(scope, receive, _send)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 189, in __call__
| with collapse_excgroups():
| File "/usr/lib64/python3.12/contextlib.py", line 158, in __exit__
| self.gen.throw(value)
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/_utils.py", line 91, in collapse_excgroups
| raise exc
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 261, in __call__
| await wrap(partial(self.listen_for_disconnect, receive))
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 257, in wrap
| await func()
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 234, in listen_for_disconnect
| message = await receive()
| ^^^^^^^^^^^^^^^
| File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 56, in wrapped_receive
| raise RuntimeError(f"Unexpected message received: {msg['type']}")
| RuntimeError: Unexpected message received: http.request
+------------------------------------
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/andrew/.local/lib/python3.12/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/errors.py", line 186, in __call__
raise exc
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 189, in __call__
with collapse_excgroups():
File "/usr/lib64/python3.12/contextlib.py", line 158, in __exit__
self.gen.throw(value)
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/_utils.py", line 91, in collapse_excgroups
raise exc
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 261, in __call__
await wrap(partial(self.listen_for_disconnect, receive))
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 257, in wrap
await func()
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/responses.py", line 234, in listen_for_disconnect
message = await receive()
^^^^^^^^^^^^^^^
File "/home/andrew/.local/lib/python3.12/site-packages/starlette/middleware/base.py", line 56, in wrapped_receive
raise RuntimeError(f"Unexpected message received: {msg['type']}")
RuntimeError: Unexpected message received: http.request
This was with Fedora 39 with Python 3.12.1 and fastapi 0.109.0 installed via pip(1)
Looking through git-log(1) these look potentially interesting to look at
commit 567545213d95e608b54ce92bfc33fac4327a9f93
Author: Max Romanov <[email protected]>
Date: Tue Jul 20 10:37:50 2021 +0300
Python: fixing ASGI receive() issues.
The receive() call never blocks for a GET request and always returns the sam
e
empty body message. The Starlette framework creates a separate task when
receive() is called in a loop until an 'http.disconnect' message is received
.
The 'http.disconnect' message was previously issued after the response heade
r
had been sent. However, the correct behavior is to respond with
'http.disconnect' after sending the response is complete.
This closes #564 issue on GitHub.
commit dfbdc1c11a201e46d61f4bc61cfbe5741fc4fd70
Author: Max Romanov <[email protected]>
Date: Tue Jul 20 10:37:53 2021 +0300
Python: fixing exceptions in Future.set_result for ASGI implementation.
An ASGI application can cancel the Future object returned by the receive()
call. In this case, Unit's ASGI implementation should not call set_result()
because the Future is already handled. In particular, the Starlette framewo
rk
was noted to cancel the received Future.
This patch adds a done() check for the Future before attempting a set_result
().
This is related to #564 issue on GitHub.
Tomorrow, I plan to test out specific starlette commits to pinpoint when exactly the problems appeared.
(You can pip install specific commits from github, see, e.g., https://stackoverflow.com/questions/13685920/install-specific-git-commit-with-pip)
I can confirm that the RuntimeError: Unexpected message received error for POST requests started with starlette commit https://github.com/encode/starlette/commit/554b9e21f6161a6d83b4ebb90909282114266317
If I have that commit, I get the error. If i go one commit back in time, the error goes away.
As for the "invalid state" error for the GET requests, they start with starlette commit https://github.com/encode/starlette/commit/11a3f1227e69a29fc9dc56f348f982cb5372a1d1
Not yet I'm afraid, I'm sure any updates will be posted here, but I don't think there is anyone actively working on this currently, so far it has really just been an information gathering exercise.
Hi I am facing the exact same issue. Is there any progress, or has anyone found some workaround for it?
I am not following this very closely anymore because I switched from FastAPI to litestar, which works great. Litestar even recommends NGINX Unit in their docs and it is very actively maintained.
With FastAPI, the only way I found around it was to use an older version, fastapi==0.107.0 starlette==0.28.0 (Then again, I have not tried the latest version of FastAPI/starlette because I stopped using it.)