In http2, the read timeout of the request holding _read_lock applies to all overlapping requests

[nmlorg]

Hi again.

I think the read timeout of the request that won the _read_lock lottery applies to all overlapping requests:

    with httpcore.ConnectionPool(http1=False, http2=True) as pool, h2server.run() as server:
        url = f'http://127.0.0.1:{server.port}/'

        def request(timeout):
            try:
                return pool.request('GET', url, extensions={'timeout': {'read': timeout}})
            except:
                logging.exception('timeout=%s:', timeout)

        def notimeout():
            logging.info('No timeout:')
            logging.info('%s', request(20))

        def timeout():
            logging.info('Timeout:')
            logging.info('%s', request(.5))

        t1 = threading.Thread(target=notimeout)
        t1.start()
        t1.join()

   94 <Thread-1 (notimeout)> synctest.py:24] No timeout:
 1140 <Thread-1 (notimeout)> synctest.py:25] <Response [200]>

👍
 

        t1 = threading.Thread(target=timeout)
        t1.start()
        t1.join()

   92 <Thread-1 (timeout)> synctest.py:28] Timeout:
  595 <Thread-1 (timeout)> synctest.py:21] timeout=0.5:
Traceback (most recent call last):
  File "synctest.py", line 19, in request
    return pool.request('GET', url, extensions={'timeout': {'read': timeout}})
  File "httpcore/_sync/interfaces.py", line 43, in request
    response = self.handle_request(request)
  File "httpcore/_sync/connection_pool.py", line 216, in handle_request
    raise exc from None
  File "httpcore/_sync/connection_pool.py", line 196, in handle_request
    response = connection.handle_request(
  File "httpcore/_sync/connection.py", line 101, in handle_request
    return self._connection.handle_request(request)
  File "httpcore/_sync/http2.py", line 185, in handle_request
    raise exc
  File "httpcore/_sync/http2.py", line 148, in handle_request
    status, headers = self._receive_response(
  File "httpcore/_sync/http2.py", line 292, in _receive_response
    event = self._receive_stream_event(request, stream_id)
  File "httpcore/_sync/http2.py", line 333, in _receive_stream_event
    self._receive_events(request, stream_id)
  File "httpcore/_sync/http2.py", line 367, in _receive_events
    events = self._read_incoming_data(request)
  File "httpcore/_sync/http2.py", line 458, in _read_incoming_data
    raise exc
  File "httpcore/_sync/http2.py", line 444, in _read_incoming_data
    data = self._network_stream.read(self.READ_NUM_BYTES, timeout)
  File "httpcore/_backends/sync.py", line 124, in read
    with map_exceptions(exc_map):
  File "/usr/lib/python3.11/contextlib.py", line 155, in __exit__
    self.gen.throw(typ, value, traceback)
  File "httpcore/_exceptions.py", line 14, in map_exceptions
    raise to_exc(exc) from exc
httpcore.ReadTimeout: timed out
  596 <Thread-1 (timeout)> synctest.py:29] None

👍
 

        t1 = threading.Thread(target=notimeout)
        t1.start()

        t2 = threading.Thread(target=timeout)
        t2.start()

        t1.join()
        t2.join()

   93 <Thread-1 (notimeout)> synctest.py:24] No timeout:
   93 <Thread-2 (timeout)> synctest.py:28] Timeout:
 1140 <Thread-2 (timeout)> synctest.py:29] <Response [200]>
 1141 <Thread-1 (notimeout)> synctest.py:25] <Response [200]>

👎 — the timeout was ignored for the second request (it should have thrown an exception around t=593, but instead returned a response at t=1140).

I believe this is just because HTTP2Connection._receive_events blocks while trying to acquire _read_lock forever (so when Thread-1 calls self._network_stream.read(self.READ_NUM_BYTES, 20) while holding _read_lock, Thread-2 has to wait up to Thread-1's request's 20-second timeout).
 

        t1 = threading.Thread(target=timeout)
        t1.start()

        t2 = threading.Thread(target=notimeout)
        t2.start()

        t1.join()
        t2.join()

   93 <Thread-1 (timeout)> synctest.py:28] Timeout:
   93 <Thread-2 (notimeout)> synctest.py:24] No timeout:
  597 <Thread-1 (timeout)> synctest.py:21] timeout=0.5:
Traceback (most recent call last):
  File "synctest.py", line 19, in request
    return pool.request('GET', url, extensions={'timeout': {'read': timeout}})
  File "httpcore/_sync/interfaces.py", line 43, in request
    response = self.handle_request(request)
  File "httpcore/_sync/connection_pool.py", line 216, in handle_request
    raise exc from None
  File "httpcore/_sync/connection_pool.py", line 196, in handle_request
    response = connection.handle_request(
  File "httpcore/_sync/connection.py", line 101, in handle_request
    return self._connection.handle_request(request)
  File "httpcore/_sync/http2.py", line 185, in handle_request
    raise exc
  File "httpcore/_sync/http2.py", line 148, in handle_request
    status, headers = self._receive_response(
  File "httpcore/_sync/http2.py", line 292, in _receive_response
    event = self._receive_stream_event(request, stream_id)
  File "httpcore/_sync/http2.py", line 333, in _receive_stream_event
    self._receive_events(request, stream_id)
  File "httpcore/_sync/http2.py", line 367, in _receive_events
    events = self._read_incoming_data(request)
  File "httpcore/_sync/http2.py", line 458, in _read_incoming_data
    raise exc
  File "httpcore/_sync/http2.py", line 444, in _read_incoming_data
    data = self._network_stream.read(self.READ_NUM_BYTES, timeout)
  File "httpcore/_backends/sync.py", line 124, in read
    with map_exceptions(exc_map):
  File "/usr/lib/python3.11/contextlib.py", line 155, in __exit__
    self.gen.throw(typ, value, traceback)
  File "httpcore/_exceptions.py", line 14, in map_exceptions
    raise to_exc(exc) from exc
httpcore.ReadTimeout: timed out
  599 <Thread-1 (timeout)> synctest.py:29] None
  598 <Thread-2 (notimeout)> synctest.py:21] timeout=20:
Traceback (most recent call last):
  File "synctest.py", line 19, in request
    return pool.request('GET', url, extensions={'timeout': {'read': timeout}})
  File "httpcore/_sync/interfaces.py", line 43, in request
    response = self.handle_request(request)
  File "httpcore/_sync/connection_pool.py", line 216, in handle_request
    raise exc from None
  File "httpcore/_sync/connection_pool.py", line 196, in handle_request
    response = connection.handle_request(
  File "httpcore/_sync/connection.py", line 101, in handle_request
    return self._connection.handle_request(request)
  File "httpcore/_sync/http2.py", line 185, in handle_request
    raise exc
  File "httpcore/_sync/http2.py", line 148, in handle_request
    status, headers = self._receive_response(
  File "httpcore/_sync/http2.py", line 292, in _receive_response
    event = self._receive_stream_event(request, stream_id)
  File "httpcore/_sync/http2.py", line 333, in _receive_stream_event
    self._receive_events(request, stream_id)
  File "httpcore/_sync/http2.py", line 367, in _receive_events
    events = self._read_incoming_data(request)
  File "httpcore/_sync/http2.py", line 441, in _read_incoming_data
    raise self._read_exception  # pragma: nocover
  File "synctest.py", line 19, in request
    return pool.request('GET', url, extensions={'timeout': {'read': timeout}})
  File "httpcore/_sync/interfaces.py", line 43, in request
    response = self.handle_request(request)
  File "httpcore/_sync/connection_pool.py", line 216, in handle_request
    raise exc from None
  File "httpcore/_sync/connection_pool.py", line 196, in handle_request
    response = connection.handle_request(
  File "httpcore/_sync/connection.py", line 101, in handle_request
    return self._connection.handle_request(request)
  File "httpcore/_sync/http2.py", line 185, in handle_request
    raise exc
  File "httpcore/_sync/http2.py", line 148, in handle_request
    status, headers = self._receive_response(
  File "httpcore/_sync/http2.py", line 292, in _receive_response
    event = self._receive_stream_event(request, stream_id)
  File "httpcore/_sync/http2.py", line 333, in _receive_stream_event
    self._receive_events(request, stream_id)
  File "httpcore/_sync/http2.py", line 367, in _receive_events
    events = self._read_incoming_data(request)
  File "httpcore/_sync/http2.py", line 458, in _read_incoming_data
    raise exc
  File "httpcore/_sync/http2.py", line 444, in _read_incoming_data
    data = self._network_stream.read(self.READ_NUM_BYTES, timeout)
  File "httpcore/_backends/sync.py", line 124, in read
    with map_exceptions(exc_map):
  File "/usr/lib/python3.11/contextlib.py", line 155, in __exit__
    self.gen.throw(typ, value, traceback)
  File "httpcore/_exceptions.py", line 14, in map_exceptions
    raise to_exc(exc) from exc
httpcore.ReadTimeout: timed out
  600 <Thread-2 (notimeout)> synctest.py:25] None

👎 — Thread-2 should have been happy to run until t=20093, but was killed at t=598.

I believe this is because any time HTTP2Connection._read_incoming_data gets any exception, it saves it as self._read_exception (and reraises), and if self._read_exception is set when it begins, it just immediately raises it.

---

Am I messing something up, or should I put together another xfail test for this, or should I let you catch up first 🙂?

[tomchristie]

I think this helps illuminate that we’ve got a little bit of misdesign here, and should look at migrating read/write timeouts into a socket timeout. That also has some knock-on effects into the httpx API.

[nmlorg]

There's only [intended to be] one socket per host:port in HTTP/2, so you can't really use socket-level timeouts at all. I think you need to convert the timeout to a deadline, then work backwards at each step:

1. Convert the deadline back to a [remaining] timeout to acquire _read_lock:

      def _receive_events(…):
           remaining_timeout = _calculate_remaining_timeout(request)
           with self._read_lock.aquire(timeout=remaining_timeout):
            ⋮

2. Convert the deadline back to a [remaining] timeout to first select on the socket before recving:

       def _read_incoming_data(…):
           remaining_timeout = _calculate_remaining_timeout(request)
            ⋮
           try:
               data = self._network_stream.read(self.READ_NUM_BYTES, remaining_timeout)
           except httpcore.ReadTimeout:
               raise
           except Exception as exc:
               self._read_exception = exc
               self._connection_error = True
               raise exc
    ⋮
   class SyncStream(NetworkStream):
       def read(self, max_bytes: int, timeout: typing.Optional[float] = None) -> bytes:
           #self._sock.settimeout(timeout)
           if not select.select([self._sock.fileno()], [], [], timeout)[0]:
               raise httpcore.ReadTimeout()
           return self._sock.recv(max_bytes)