MessageReceiverState Error : Not receiving events from some partitions

[Benniah]

• Package Name: azure-eventhub
• Package Version: 5.12.0
• Package Name: azure-eventhub-checkpointstoreblob-aio
• Package Version: 1.1.4
• Operating System: Linux
• Python Version: 3.9.1

Describe the bug
I have an Evenethub Consumer client that streams data into a snowflake table running inside an azure container instance . The Eventhub has 6 partitions which the consumer client can fetch events from when started.

However after a couple of hours , the client stops receiving events from one or more partitions .When the container is manually restarted the client is bale to claim ownership of those partitions again and the stream is resumed .

To Reproduce
Steps to reproduce the behavior:

1. I am using boilerplate code from the documentation with a little modification to process and insert events into snowflake

Expected behavior
continue to receive events from all partitions

LOGS

INFO:__main__:Received events from partition: 1
INFO:uamqp.c_uamqp:CBS error occurred on connection b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.receiver:Receiver link failed to open - expecting to receive DETACH frame.
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.OPENED: 9> to <ConnectionState.CLOSE_RCVD: 10>
INFO:uamqp.receiver:Message receiver b'receiver-link-734198d4-db38-4768-877f-71d72b919bd7' state changed from <MessageReceiverState.Error: 5> to <MessageReceiverState.Error: 5> on connection: b'EHReceiver-xxxxxxxxxxx-partition0'
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.CLOSE_RCVD: 10> to <ConnectionState.END: 13>
INFO:uamqp.receiver:Message receiver b'receiver-link-734198d4-db38-4768-877f-71d72b919bd7' state changed from <MessageReceiverState.Error: 5> to <MessageReceiverState.Error: 5> on connection: b'EHReceiver-xxxxxxxxxxx-partition0'
INFO:uamqp.connection:Received Connection close event: b'amqp:connection:forced'
Connection: b'EHReceiver-xxxxxxxxxxx-partition0'
Description: b"The connection was closed by container 'af980dee699c43f3a9d903a9fcd72432_G4' because it did not have any active links in the past 60000 milliseconds. TrackingId:af980dee699c43f3a9d903a9fcd72432_G4, SystemTracker:gateway5, Timestamp:2024-06-06T09:00:42"
Details: None
INFO:uamqp.c_uamqp:b'SSL channel closed in decode_ssl_received_bytes.' (b'/project/src/vendor/azure-uamqp-c/deps/azure-c-shared-utility/adapters/tlsio_openssl.c':b'decode_ssl_received_bytes':886)
INFO:uamqp.c_uamqp:b'Error callback received in unexpected state' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'on_underlying_io_error':243)
INFO:uamqp.c_uamqp:b'Error in decode_ssl_received_bytes.' (b'/project/src/vendor/azure-uamqp-c/deps/azure-c-shared-utility/adapters/tlsio_openssl.c':b'on_underlying_io_bytes_received':935)

INFO:uamqp.async_ops.connection_async:Shutting down connection b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.authentication.cbs_auth_async:Shutting down CBS session on connection: b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.authentication.cbs_auth_async:Auth closed, destroying session on connection: b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.authentication.cbs_auth_async:Finished shutting down CBS session on connection: b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.c_uamqp:b'send called while not open' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'saslclientio_send_async':1181)
INFO:uamqp.c_uamqp:b'Cannot send encoded bytes' (b'/project/src/vendor/azure-uamqp-c/src/connection.c':b'on_bytes_encoded':268)
INFO:uamqp.c_uamqp:b'saslclientio_close called while not open' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'saslclientio_close_async':1130)
INFO:uamqp.c_uamqp:b'xio_close failed' (b'/project/src/vendor/azure-uamqp-c/src/connection.c':b'on_bytes_encoded':272)
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.END: 13> to <ConnectionState.END: 13>
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.END: 13> to <ConnectionState.END: 13>
INFO:uamqp.c_uamqp:b'saslclientio_close called while not open' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'saslclientio_close_async':1130)
INFO:uamqp.c_uamqp:b'xio_close failed' (b'/project/src/vendor/azure-uamqp-c/src/connection.c':b'connection_close':1437)
INFO:uamqp.async_ops.connection_async:Connection shutdown complete b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.START: 0> to <ConnectionState.START: 0>
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.START: 0> to <ConnectionState.START: 0>
Received events from partition: 5
INFO:__main__:Received events from partition: 5
Received events from partition: 3
INFO:__main__:Received events from partition: 3

INFO:uamqp.async_ops.client_async:Keeping 'ReceiveClientAsync' connection alive. b'EHReceiver-xxxxxxxxxxx-partition0'
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.START: 0> to <ConnectionState.END: 13>
INFO:uamqp.connection:Connection with ID b'EHReceiver-xxxxxxxxxxx-partition0' unexpectedly in an error state. Closing: False, Error: None
INFO:uamqp.c_uamqp:b'AMQP management instance not open' (b'/project/src/vendor/azure-uamqp-c/src/amqp_management.c':b'amqp_management_close':1061)
INFO:uamqp.c_uamqp:CBS for connection b'EHReceiver-xxxxxxxxxxx-partition0' completed opening with status: 2
WARNING:uamqp.async_ops.connection_async:ConnectionClose('ErrorCodes.UnknownError: Connection in an unexpected error state.')
INFO:uamqp.async_ops.client_async:Connection keep-alive for 'ReceiveClientAsync' failed: ConnectionClose('ErrorCodes.UnknownError: Connection in an unexpected error state.').
INFO:uamqp.receiver:Message receiver b'receiver-link-4e45327d-1d30-465b-bae4-ff5816f2331f' state changed from <MessageReceiverState.Idle: 1> to <MessageReceiverState.Opening: 2> on connection: b'EHReceiver-xxxxxxxxxxx-partition0'
INFO:uamqp.receiver:Receiver link failed to open - expecting to receive DETACH frame.
WARNING:uamqp.async_ops.connection_async:ConnectionClose('ErrorCodes.UnknownError: Connection in an unexpected error state.')
INFO:uamqp.async_ops.client_async:CBS session pending b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.async_ops.client_async:Closing exclusive connection b'EHReceiver-xxxxxxxxxxx-partition0'.
Received events from partition: 5
INFO:__main__:Received events from partition: 5
Received events from partition: 1
INFO:__main__:Received events from partition: 1
INFO:uamqp.async_ops.connection_async:Shutting down connection b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.authentication.cbs_auth_async:Shutting down CBS session on connection: b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.c_uamqp:Token put complete with result: 2, status: 0, description: b'CBS Session closed.', connection: b'EHReceiver-xxxxxxxxxxx-partition0'
INFO:uamqp.authentication.cbs_auth_async:Auth closed, destroying session on connection: b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.authentication.cbs_auth_async:Finished shutting down CBS session on connection: b'EHReceiver-xxxxxxxxxxx-partition0'.
INFO:uamqp.c_uamqp:b'send called while not open' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'saslclientio_send_async':1181)
INFO:uamqp.c_uamqp:b'Cannot send encoded bytes' (b'/project/src/vendor/azure-uamqp-c/src/connection.c':b'on_bytes_encoded':268)
INFO:uamqp.c_uamqp:b'saslclientio_close called while not open' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'saslclientio_close_async':1130)
INFO:uamqp.c_uamqp:b'xio_close failed' (b'/project/src/vendor/azure-uamqp-c/src/connection.c':b'on_bytes_encoded':272)
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.END: 13> to <ConnectionState.END: 13>
INFO:uamqp.connection:Connection b'EHReceiver-xxxxxxxxxxx-partition0' state changed from <ConnectionState.END: 13> to <ConnectionState.END: 13>
INFO:uamqp.c_uamqp:b'saslclientio_close called while not open' (b'/project/src/vendor/azure-uamqp-c/src/saslclientio.c':b'saslclientio_close_async':1130)
INFO:uamqp.c_uamqp:b'xio_close failed' (b'/project/src/vendor/azure-uamqp-c/src/connection.c':b'connection_close':1437)
INFO:uamqp.async_ops.connection_async:Connection shutdown complete b'EHReceiver-xxxxxxxxxxx-partition0'.

Additional context
using uamqp_transport=True

[github-actions]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @kasun04.

[kashifkhan]

Thank you for the feedback @Benniah. A few questions for you

• From this log line because it did not have any active links in the past 60000 milliseconds it seems that something is blocking the creation of links after opening a connection. Are there any processes running or is the container running out of resources?
• Does this error happen when you pass in uamqp_transport=False

[Benniah]

Hi @kashifkhan ,

• Based on the Azure container Instance resource monitor , resources do not seem constrained .
• Regarding processes , we do have an async task to process events before inserting into snowflake.
• I will give uamqp_transport=False a try and let you know

[kashifkhan]

@Benniah based on #2 , is it possible if that task is slowing down things enough that there is a delay on the network?