encode / uvicorn

An ASGI web server, for Python. 🦄
https://www.uvicorn.org/
BSD 3-Clause "New" or "Revised" License
8.57k stars 745 forks source link

Fix spurious LocalProtocolError errors when processing pipelined requests #2243

Closed marcinsulikowski closed 9 months ago

marcinsulikowski commented 9 months ago

Summary

This is a fix for https://github.com/encode/uvicorn/issues/1637 which was closed due to no reproduction. I was able to find the reproduction steps and and a fix (see my recent comment in the issue).

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.

Checklist