-
-
Notifications
You must be signed in to change notification settings - Fork 695
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
Can't handle event type ConnectionClosed when role=SERVER and state=SEND_RESPONSE #1637
Comments
>>> here is more information <<<how to start the serveruvicorn app:app --reload --host 0.0.0.0 --timeout-keep-alive 1 versions
|
I cannot reproduce it. 👀 |
For other people encountering such issue - This might be caused when your server has CPU starvation. So each client, making a request, expect a keep alive that is configured by uvicorn to 5 by default. That keepalive, if the server process is starved, wont happen on time and thus, client will bail the connection with an execute of "RemoteDisconnect" while the server will show a traceback as mentioned on the PR description. The solution here, would be to allow more CPU for the process or find the bottleneck on the server process to allow it sending the keepalive on time. (or, course, increase the default keepalive on the server from 5 to whatever is needed, but i guess, that would mask other issues) |
…ests When uvicorn receives a request very soon after it sent the previous response, or when it receives pipelined requests, the second request may spuriously fail if the ASGI app takes more time to process it than uvicorn's `timeout_keep_alive`. This happens because uvicorn arms the keep-alive timer as the last step of handling the first request, which is after the second request was already received from the network (which normally is the only place where uvicorn disarms the keep-alive timer). In such cases the timer may fire while uvicorn is still waiting for a response from the ASGI app: Exception in callback H11Protocol.timeout_keep_alive_handler() handle: <TimerHandle when=335245.867740771 H11Protocol.timeout_keep_alive_handler()> Traceback (most recent call last): File "/usr/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 363, in timeout_keep_alive_handler self.conn.send(event) File "venv/lib/python3.12/site-packages/h11/_connection.py", line 512, in send data_list = self.send_with_data_passthrough(event) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 537, in send_with_data_passthrough self._process_event(self.our_role, event) File "venv/lib/python3.12/site-packages/h11/_connection.py", line 272, in _process_event self._cstate.process_event(role, type(event), server_switch_event) File "venv/lib/python3.12/site-packages/h11/_state.py", line 293, in process_event self._fire_event_triggered_transitions(role, _event_type) File "venv/lib/python3.12/site-packages/h11/_state.py", line 311, in _fire_event_triggered_transitions raise LocalProtocolError( h11._util.LocalProtocolError: can't handle event type ConnectionClosed when role=SERVER and state=SEND_RESPONSE When this happens, the connection is left in the `ERROR` state and when a response to the second request is ready to be sent, this fails: ERROR: Exception in ASGI application Traceback (most recent call last): File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 408, in run_asgi result = await app( # type: ignore[func-returns-value] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__ return await self.app(scope, receive, send) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ (...) File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 490, in send output = self.conn.send(event=response) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 512, in send data_list = self.send_with_data_passthrough(event) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 527, in send_with_data_passthrough raise LocalProtocolError("Can't send data when our state is ERROR") h11._util.LocalProtocolError: Can't send data when our state is ERROR We fix this by ensuring that the keep-alive timer is disarmed before starting to process a pipelined request. Closes encode#1637
…ests When uvicorn receives a request very soon after it sent the previous response, or when it receives pipelined requests, the second request may spuriously fail if the ASGI app takes more time to process it than uvicorn's `timeout_keep_alive`. This happens because uvicorn arms the keep-alive timer as the last step of handling the first request, which is after the second request was already received from the network (which normally is the only place where uvicorn disarms the keep-alive timer). In such cases the timer may fire while uvicorn is still waiting for a response from the ASGI app: Exception in callback H11Protocol.timeout_keep_alive_handler() handle: <TimerHandle when=335245.867740771 H11Protocol.timeout_keep_alive_handler()> Traceback (most recent call last): File "/usr/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 363, in timeout_keep_alive_handler self.conn.send(event) File "venv/lib/python3.12/site-packages/h11/_connection.py", line 512, in send data_list = self.send_with_data_passthrough(event) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 537, in send_with_data_passthrough self._process_event(self.our_role, event) File "venv/lib/python3.12/site-packages/h11/_connection.py", line 272, in _process_event self._cstate.process_event(role, type(event), server_switch_event) File "venv/lib/python3.12/site-packages/h11/_state.py", line 293, in process_event self._fire_event_triggered_transitions(role, _event_type) File "venv/lib/python3.12/site-packages/h11/_state.py", line 311, in _fire_event_triggered_transitions raise LocalProtocolError( h11._util.LocalProtocolError: can't handle event type ConnectionClosed when role=SERVER and state=SEND_RESPONSE When this happens, the connection is left in the `ERROR` state and when a response to the second request is ready to be sent, this fails: ERROR: Exception in ASGI application Traceback (most recent call last): File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 408, in run_asgi result = await app( # type: ignore[func-returns-value] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__ return await self.app(scope, receive, send) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ (...) File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 490, in send output = self.conn.send(event=response) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 512, in send data_list = self.send_with_data_passthrough(event) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 527, in send_with_data_passthrough raise LocalProtocolError("Can't send data when our state is ERROR") h11._util.LocalProtocolError: Can't send data when our state is ERROR We fix this by ensuring that the keep-alive timer is disarmed before starting to process a pipelined request. Closes encode#1637
@Yangruipis, @Kludex, I am hitting this error very frequently in a quite complex application I am working on. After looking at the problem a bit closer, it happens when the server receives a request very fast after sending a response for the previous one on the same connection, before it manages to call It could not create a simple and reliable reproducer of the scenario above, but the same problem can be very reliably reproduced in another way: by pipelining two requests, when the second request takes longer than import asyncio
import uvicorn
from fastapi import FastAPI
app = FastAPI()
@app.get("/")
async def root():
await asyncio.sleep(3)
return {"msg": "Hello World"}
async def main():
# Start uvicorn in a background task
config = uvicorn.Config(app, port=8000, timeout_keep_alive=1)
server = uvicorn.Server(config)
uvicorn_task = asyncio.create_task(server.serve())
# After it starts, try making two HTTP requests.
await asyncio.sleep(1)
print("Sending requests")
reader, writer = await asyncio.open_connection("localhost", 8000)
writer.write(b"GET / HTTP/1.1\r\nHost: localhost\r\nConnection: keep-alive\r\n\r\n")
writer.write(b"GET / HTTP/1.1\r\nHost: localhost\r\nConnection: keep-alive\r\n\r\n")
await writer.drain()
while data := await reader.read(100):
print(data.decode("utf-8"))
print("Server closed the connection")
server.should_exit = True
await uvicorn_task
if __name__ == "__main__":
asyncio.run(main()) The script should print two
See PR #2243 for a proposal which fixes the problem. |
…ests When uvicorn receives a request very soon after it sent the previous response, or when it receives pipelined requests, the second request may spuriously fail if the ASGI app takes more time to process it than uvicorn's `timeout_keep_alive`. This happens because uvicorn arms the keep-alive timer as the last step of handling the first request, which is after the second request was already received from the network (which normally is the only place where uvicorn disarms the keep-alive timer). In such cases the timer may fire while uvicorn is still waiting for a response from the ASGI app: Exception in callback H11Protocol.timeout_keep_alive_handler() handle: <TimerHandle when=335245.867740771 H11Protocol.timeout_keep_alive_handler()> Traceback (most recent call last): File "/usr/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 363, in timeout_keep_alive_handler self.conn.send(event) File "venv/lib/python3.12/site-packages/h11/_connection.py", line 512, in send data_list = self.send_with_data_passthrough(event) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 537, in send_with_data_passthrough self._process_event(self.our_role, event) File "venv/lib/python3.12/site-packages/h11/_connection.py", line 272, in _process_event self._cstate.process_event(role, type(event), server_switch_event) File "venv/lib/python3.12/site-packages/h11/_state.py", line 293, in process_event self._fire_event_triggered_transitions(role, _event_type) File "venv/lib/python3.12/site-packages/h11/_state.py", line 311, in _fire_event_triggered_transitions raise LocalProtocolError( h11._util.LocalProtocolError: can't handle event type ConnectionClosed when role=SERVER and state=SEND_RESPONSE When this happens, the connection is left in the `ERROR` state and when a response to the second request is ready to be sent, this fails: ERROR: Exception in ASGI application Traceback (most recent call last): File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 408, in run_asgi result = await app( # type: ignore[func-returns-value] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__ return await self.app(scope, receive, send) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ (...) File "venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 490, in send output = self.conn.send(event=response) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 512, in send data_list = self.send_with_data_passthrough(event) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "venv/lib/python3.12/site-packages/h11/_connection.py", line 527, in send_with_data_passthrough raise LocalProtocolError("Can't send data when our state is ERROR") h11._util.LocalProtocolError: Can't send data when our state is ERROR We fix this by ensuring that the keep-alive timer is disarmed before starting to process a pipelined request. Closes encode#1637
I've reopened. I'll check this in some days. Thanks. |
Related to #111
#1636 may be a solution
Reproducing
1. server code
2. locust client
3. call
It will take 30s to reproduce this issue
Traceback logs
Important
The text was updated successfully, but these errors were encountered: