Server failed to properly handle request cancel

[vmagamedov]

Exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 310, in request_handler
    await method.func(stream)
  File "/usr/local/lib/python3.6/dist-packages/featureflags/server/rpc/service.py", line 51, in Exchange
    await self._queue.StoreStats.add(task, timeout=timeout)
  File "/usr/local/lib/python3.6/dist-packages/taskqueue/client/queue.py", line 21, in add
    await self._task_queue_stub.Add(task, timeout=timeout)
  File "/usr/local/lib/python3.6/dist-packages/grpclib/client.py", line 473, in __call__
    return await stream.recv_message()
  File "/usr/local/lib/python3.6/dist-packages/grpclib/client.py", line 286, in recv_message
    await self.recv_initial_metadata()
  File "/usr/local/lib/python3.6/dist-packages/grpclib/client.py", line 221, in recv_initial_metadata
    headers = await self._stream.recv_headers()
  File "/usr/local/lib/python3.6/dist-packages/grpclib/protocol.py", line 215, in recv_headers
    return await self.__headers__.get()
  File "/usr/lib/python3.6/asyncio/queues.py", line 167, in get
    yield from getter
concurrent.futures._base.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/h2/connection.py", line 585, in _get_or_create_stream
    return self.streams[stream_id]
KeyError: 48141

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 325, in request_handler
    raise
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 220, in __aexit__
    status_message=status_message)
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 170, in send_trailing_metadata
    await self._stream.send_headers(headers, end_stream=True)
  File "/usr/local/lib/python3.6/dist-packages/grpclib/protocol.py", line 267, in send_headers
    end_stream=end_stream)
  File "/usr/local/lib/python3.6/dist-packages/h2/connection.py", line 763, in send_headers
    stream_id, AllowedStreamIDs(self.config.client_side)
  File "/usr/local/lib/python3.6/dist-packages/h2/connection.py", line 587, in _get_or_create_stream
    return self._begin_new_stream(stream_id, allowed_ids)
  File "/usr/local/lib/python3.6/dist-packages/h2/connection.py", line 454, in _begin_new_stream
    raise StreamIDTooLowError(stream_id, highest_stream_id)
h2.exceptions.StreamIDTooLowError: StreamIDTooLowError: 48141 is lower than 48143

[sergeyspatar]

@vmagamedov I encountered the same error in my project:

2018-10-23 18:19:21,661 [16700] ERROR grpclib.server: Application error
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/h2/connection.py", line 585, in _get_or_create_stream
    return self.streams[stream_id]
KeyError: 6059297

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 327, in request_handler
    await method.func(stream)
  File "/home/spatar/test/test.py", line 93, in test
    dst_manual_type=dst_manual_type
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 135, in send_message
    await self.send_initial_metadata()
  File "/usr/local/lib/python3.6/dist-packages/grpclib/server.py", line 114, in send_initial_metadata
    await self._stream.send_headers(headers)
  File "/usr/local/lib/python3.6/dist-packages/grpclib/protocol.py", line 272, in send_headers
    end_stream=end_stream)
  File "/usr/lib/python3/dist-packages/h2/connection.py", line 763, in send_headers
    stream_id, AllowedStreamIDs(self.config.client_side)
  File "/usr/lib/python3/dist-packages/h2/connection.py", line 587, in _get_or_create_stream
    return self._begin_new_stream(stream_id, allowed_ids)
  File "/usr/lib/python3/dist-packages/h2/connection.py", line 454, in _begin_new_stream
    raise StreamIDTooLowError(stream_id, highest_stream_id)
h2.exceptions.StreamIDTooLowError: StreamIDTooLowError: 6059297 is lower than 6059457

And on the client side all RPC requests were timing out.

Do you have ETA for this bug fix?

[vmagamedov]

Will try to figure out how to reproduce this bug in tests soon, sorry, I'm totally forgot about this issue

[vmagamedov]

It is not so easy to reproduce this error in tests, but I think that I found the cause: python-hyper/h2#1175, and it is possible to workaround this issue in grpclib. @sergeyspatar, I see that you forked this project, are you going to submit a fix?