Azure / azure-sdk-for-python

This repository is for active development of the Azure SDK for Python. For consumers of the SDK we recommend visiting our public developer docs at https://learn.microsoft.com/python/azure/ or our versioned developer docs at https://azure.github.io/azure-sdk-for-python.
MIT License
4.63k stars 2.84k forks source link

The event-hubs receiver is not stable in python #5305

Closed yunhaoling closed 4 years ago

yunhaoling commented 5 years ago

@MashellHan commented on Wed Apr 17 2019

Hello. I am using eventhubs-python sdk to receive events from eventhub, but the receiver is not much stable, it always is broken by some reasons.

the log shows: 2019-04-17 17:05:31,160 uamqp.c_uamqp INFO b'Failure: sending socket failed 10054.' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\deps\azure-c-shared-utility\adapters\socketio_win32.c':b'socketio_send':422) 2019-04-17 17:05:31,160 uamqp.c_uamqp INFO b'xio_send failed' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\deps\azure-c-shared-utility\adapters\tlsio_schannel.c':b'send_chunk':484) 2019-04-17 17:05:31,160 uamqp.c_uamqp INFO b'send_chunk failed' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\deps\azure-c-shared-utility\adapters\tlsio_schannel.c':b'internal_send':525) 2019-04-17 17:05:31,160 uamqp.c_uamqp INFO b'send failed' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\deps\azure-c-shared-utility\adapters\tlsio_schannel.c':b'tlsio_schannel_send':1263) 2019-04-17 17:05:31,160 uamqp.c_uamqp INFO b'xio_send failed' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\saslclientio.c':b'saslclientio_send_async':1190) 2019-04-17 17:05:31,160 uamqp.c_uamqp INFO b'Cannot send encoded bytes' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\connection.c':b'on_bytes_encoded':268) 2019-04-17 17:05:31,348 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.OPENED: 9> to <ConnectionState.END: 13> 2019-04-17 17:05:31,348 uamqp.connection INFO Connection with ID b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' unexpectedly in an error state. Closing: False, Error: None 2019-04-17 17:05:31,426 uamqp.c_uamqp INFO CBS error occured on connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'. 2019-04-17 17:05:31,457 uamqp.receiver INFO Message receiver b'receiver-link-0d5f18a8-80a5-42c1-9a6b-2e12601f6246' state changed from <MessageReceiverState.Open: 2> to <MessageReceiverState.Idle: 0> on connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' 2019-04-17 17:05:31,521 uamqp.connection WARNING ConnectionClose('ErrorCodes.UnknownError: Connection in an unexpected error state.',) 2019-04-17 17:05:31,646 azure.eventhub.receiver INFO Receiver detached. Attempting reconnect. 2019-04-17 17:05:31,708 uamqp.connection INFO Shutting down connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'. 2019-04-17 17:05:31,708 uamqp.authentication.cbs_auth INFO Shutting down CBS session on connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'. 2019-04-17 17:05:31,708 uamqp.authentication.cbs_auth INFO Auth closed, destroying session on connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'. 2019-04-17 17:05:31,724 uamqp.authentication.cbs_auth INFO Finished shutting down CBS session on connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'. 2019-04-17 17:05:31,724 uamqp.c_uamqp INFO b'send called while not open' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\saslclientio.c':b'saslclientio_send_async':1181) 2019-04-17 17:05:31,724 uamqp.c_uamqp INFO b'Cannot send encoded bytes' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\connection.c':b'on_bytes_encoded':268) 2019-04-17 17:05:31,724 uamqp.c_uamqp INFO b'saslclientio_close called while not open' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\saslclientio.c':b'saslclientio_close_async':1130) 2019-04-17 17:05:31,724 uamqp.c_uamqp INFO b'xio_close failed' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\connection.c':b'on_bytes_encoded':272) 2019-04-17 17:05:31,724 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.END: 13> to <ConnectionState.END: 13> 2019-04-17 17:05:31,724 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.END: 13> to <ConnectionState.END: 13> 2019-04-17 17:05:31,724 uamqp.c_uamqp INFO b'saslclientio_close called while not open' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\saslclientio.c':b'saslclientio_close_async':1130) 2019-04-17 17:05:31,724 uamqp.c_uamqp INFO b'xio_close failed' (b'C:\Users\antisch\Documents\GitHub\azure-uamqp-python\src\vendor\azure-uamqp-c\src\connection.c':b'connection_close':1437) 2019-04-17 17:05:31,724 uamqp.connection INFO Connection shutdown complete b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'. 2019-04-17 17:05:32,068 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.UNKNOWN: 999> to <ConnectionState.START: 0> 2019-04-17 17:05:32,677 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.START: 0> to <ConnectionState.START: 0> 2019-04-17 17:05:33,679 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.START: 0> to <ConnectionState.HDR_SENT: 2> 2019-04-17 17:05:33,929 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.HDR_SENT: 2> to <ConnectionState.HDR_EXCH: 3> 2019-04-17 17:05:33,929 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.HDR_EXCH: 3> to <ConnectionState.OPEN_SENT: 7> 2019-04-17 17:05:34,179 uamqp.connection INFO Connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' state changed from <ConnectionState.OPEN_SENT: 7> to <ConnectionState.OPENED: 9> 2019-04-17 17:05:34,867 uamqp.c_uamqp INFO CBS for connection b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' completed opening with status: 0 2019-04-17 17:05:35,304 uamqp.c_uamqp INFO Token put complete with result: 0, status: 202, description: b'Accepted', connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' 2019-04-17 17:05:35,509 uamqp.receiver INFO Message receiver b'receiver-link-55242f99-4a98-4f81-93b1-887a1f570f1b' state changed from <MessageReceiverState.Idle: 0> to <MessageReceiverState.Opening: 1> on connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10' 2019-04-17 17:05:35,823 uamqp.receiver INFO Message receiver b'receiver-link-55242f99-4a98-4f81-93b1-887a1f570f1b' state changed from <MessageReceiverState.Opening: 1> to <MessageReceiverState.Open: 2> on connection: b'EHReceiver-c6603164-1173-4f94-a356-0fe1d0b8745d-partition10'

for more, i have 16 partitions and 16 receivers for each partition, each receiver is running on an individual process. the basic code i used is like that: //////////////////////////////////////////////////////////////////////////////// receiver = client.add_receiver("$default", partition, Offset, prefetch=300, keep_alive=0) client.run() batch = receiver.receive(max_batch_size=100, timeout=0) while batch: ... batch = receiver.receive(max_batch_size=100, timeout=0) ... /////////////////////////////////////////////////////////////////////////////////


@annatisch commented on Thu Apr 18 2019

Thanks @MashellHan for the report! How frequently are you seeing this behaviour? The receiver should be able to automatically reconnect itself in the case of a failure - is this happening?


@MashellHan commented on Fri Apr 19 2019

Thanks anatisch for response. it happens within several hours but not fixed. from the log, i could see the reconnect info, it goes to crash after several reconnects.

cyberminder commented 5 years ago

I am also facing the same issue. sometimes its reconnecting but sometimes its failed.

hbensalem commented 5 years ago

I also have the same issue. @yunhaoling could you please share your receiver code, I am struggling to read from multiple partitions. Thanks !

yunhaoling commented 4 years ago

Hello @MashellHan ,@cyberminder, @hbensalem

We have recently released eventhub 5.0.0 which has a new design, stability and performance are improved. Please take a try.