Asyncio task exception upon unhandled ExecuteBatchError exception

[marcosatti]

What version of gRPC and what language are you using?

gRPC Python 1.49.0

What operating system (Linux, Windows,...) and version?

Docker image: python:3.10-alpine

What runtime / compiler are you using (e.g. python version or version of gcc)

Python 3.10.7

What did you do?

Exception being raised internally within the servicer method handler due to satellite-like internet connection (upstream cloud connection timed out).
Cannot reproduce reliably - something to do with timing of exceptions being raised. Seems to be a rare problem.

What did you expect to see?

No gRPC future error upon an exception being raised internal to the servicer method handler. The client is notified of a failure instead upon service call return.

What did you see instead?

2022-09-18 06:22:41,433 - grpc._cython.cygrpc - ERROR - Unexpected [OperationTimeout] raised by servicer method [/UploadReport]
Traceback (most recent call last):
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/server.pyx.pxi", line 682, in grpc._cython.cygrpc._handle_exceptions
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/server.pyx.pxi", line 796, in _handle_rpc
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/server.pyx.pxi", line 547, in _handle_unary_unary_rpc
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/server.pyx.pxi", line 404, in _finish_handler_with_unary_response
  ...
  <our app code stack trace - omitted>
  ...
  File "/usr/local/lib/python3.10/site-packages/azure/iot/device/iothub/abstract_clients.py", line 505, in on_method_request_received
    self._generic_receive_handler_setter(
  File "/usr/local/lib/python3.10/site-packages/azure/iot/device/iothub/sync_clients.py", line 151, in _generic_receive_handler_setter
    self._enable_feature(feature_name)
  File "/usr/local/lib/python3.10/site-packages/azure/iot/device/iothub/sync_clients.py", line 107, in _enable_feature
    callback.wait_for_completion()
  File "/usr/local/lib/python3.10/site-packages/azure/iot/device/common/evented_callback.py", line 69, in wait_for_completion
    raise self.exception
azure.iot.device.common.pipeline.pipeline_exceptions.OperationTimeout: Transport timeout on connection operation
2022-09-18 06:22:41,437 - asyncio - ERROR - Task exception was never retrieved
future: <Task finished name='Task-37924' coro=<<coroutine without __name__>()> exception=ExecuteBatchError('Failed "execute_batch": (<grpc._cython.cygrpc.SendInitialMetadataOperation object at 0x7f8abc1aac00>, <grpc._cython.cygrpc.SendStatusFromServerOperation object at 0x7f8abb526330>)')>
Traceback (most recent call last):
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/server.pyx.pxi", line 719, in _handle_exceptions
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/callback_common.pyx.pxi", line 184, in _send_error_status_from_server
  File "src/python/grpcio/grpc/_cython/_cygrpc/aio/callback_common.pyx.pxi", line 98, in execute_batch
grpc._cython.cygrpc.ExecuteBatchError: Failed "execute_batch": (<grpc._cython.cygrpc.SendInitialMetadataOperation object at 0x7f8abc1aac00>, <grpc._cython.cygrpc.SendStatusFromServerOperation object at 0x7f8abb526330>)

Anything else we should know about your project / environment?

Haven't turned on verbose gRPC logging - if you think it's worth while I can try.

Maybe related to #30984 ?

[XuanWang-Amos]

It's similar to this issue: #31570

The server failed with OperationTimeout error and gRPC was trying to send error status to client by calling _send_error_status_from_server, but gRPC core failed and returned with ExecuteBatchError.

So we'll indeed trying to notify client about server failure but something went wrong during this process, we'll need more logs to debug core failure.

Please comment here with logs if anyone is able to reproduce with additional environment flags:
GRPC_VERBOSITY=debug GRPC_TRACE=all,-timer,-timer_check

[njhill]

I've reproduced with debug logs: #31570 (comment)

[grpc-bot]

More than 30 days have passed since label "disposition/requires reporter action" was added. Closing this issue. Please feel free to re-open/create a new issue if this is still relevant.

[gnossen]

Closing this particular issue as a duplicate of #31570. The investigation will continue there.