azure-sdk-for-js: [Service Bus] AMQP unable to reconnect after disconnection

  • Package Name: @azure/service-bus
  • Package Version: 1.1.0
  • Operating system: node10:alpine (docker image)
  • nodejs
    • version: 10
  • browser
    • name/version:
  • typescript
    • version:
  • Is the bug related to documentation in

Describe the bug Currently we have a listener(processor) using this library as a message receiver(Service Bus Queue) and it is hosted in K8. The problem we have is suddenly our listener will get disconnection from AMQP and it would not be able to reconnect successfully. It will keep hanging there until we restarted our instance pod in K8 which is a fresh instance again.

To Reproduce Steps to reproduce the behavior:

  1. We cannot reproduce in our test environment but it happen quite frequently in our Production environment. We had DEBUG logging for azure and rhea for more logs as below. The logs below is partial but eventually it is mostly repeated.

Expected behavior

  1. AMQP connection able to reconnect for whatever reason.
  2. Suggestion: Can we get like a callback from AMQPError and let us handle what we want to do with our application ?

Additional context

Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.596Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: receiver_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.773Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_close'. Re-emitting the translated context. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.773Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Session got event: session_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.774Z rhea-promise:translate [connection-2] Translating the context for event: 'session_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: receiver_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.774Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_close'. Re-emitting the translated context. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.774Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.774Z azure:service-bus:receiver [connection-2] Clearing message renew lock timers for all the active messages. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.775Z azure:service-bus:error [connection-2] 'receiver_close' event occurred on the receiver 'taskEmail-79f45cbe-537b-3345-9028-bce8ae42467b' with address 'taskEmail' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.776Z rhea-promise:error [connection-2] The receiver is open ? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Session got event: session_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.776Z rhea-promise:translate [connection-2] Translating the context for event: 'session_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.776Z azure:service-bus:receiver [connection-2] Clearing message renew lock timers for all the active messages. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.776Z azure:service-bus:error [connection-2] 'session_close' event occurred on the session of receiver 'taskEmail-79f45cbe-537b-3345-9028-bce8ae42467b' with address 'taskEmail' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.776Z rhea-promise:error [connection-2] The receiver is open ? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: sender_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.777Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: receiver_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.777Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_close'. Re-emitting the translated context. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.777Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Session got event: session_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.777Z rhea-promise:translate [connection-2] Translating the context for event: 'session_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Connection got event: connection_close 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.777Z rhea-promise:translate [connection-2] Translating the context for event: 'connection_close'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.779Z rhea-promise:receiver [connection-2] receiver has been closed, now closing it's session. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.779Z rhea-promise:error [connection-2] The session is open ? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.779Z rhea-promise:receiver [connection-2] receiver has been closed, now closing it's session. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.779Z rhea-promise:error [connection-2] The session is open ? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.779Z azure:service-bus:error [connection-2] close() method of Receiver 'taskEmail-79f45cbe-537b-3345-9028-bce8ae42467b' with address 'taskEmail' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.779Z azure:service-bus:error [connection-2] Receiver 'taskEmail-79f45cbe-537b-3345-9028-bce8ae42467b' with address 'taskEmail' is open? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.780Z azure:service-bus:error [connection-2] The receiver 'taskEmail-79f45cbe-537b-3345-9028-bce8ae42467b' with address 'taskEmail' is not open and is not currently establishing itself. Hence let's try to connect. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.780Z azure:service-bus:error [connection-2] close() method of Receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.781Z azure:service-bus:error [connection-2] Receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' is open? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.781Z azure:service-bus:error [connection-2] Receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' is open? -> false 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.781Z azure:service-bus:error [connection-2] The receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' is open -> false and is connecting -> true. Hence not reconnecting. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Connection got event: connection_open 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.893Z rhea-promise:translate [connection-2] Translating the context for event: 'connection_open'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Session got event: session_open 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.894Z rhea-promise:translate [connection-2] Translating the context for event: 'session_open'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: sender_open 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.897Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_open'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: sender_flow 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.897Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_flow'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: sendable 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.897Z rhea-promise:translate [connection-2] Translating the context for event: 'sendable'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: receiver_open 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.899Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_open'. Re-emitting the translated context. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.899Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_open'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.899Z rhea-promise:receiver [connection-2] Resolving the promise with amqp receiver 'cbs-0af819c5-f5d1-3541-be3c-5e6ba2445be4'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Received disposition for outgoing transfers 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: accepted 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.956Z rhea-promise:translate [connection-2] Translating the context for event: 'accepted'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: settled 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.956Z rhea-promise:translate [connection-2] Translating the context for event: 'settled'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:01 GMT rhea:events [connection-2] Link got event: message 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.957Z rhea-promise:receiver [connection-2] receiver got event: 'message'. Re-emitting the translated context. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.957Z rhea-promise:translate [connection-2] Translating the context for event: 'message'. 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:01.957Z azure:service-bus:error [connection-2] Trying to create receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with options { name: 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f', 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   autoaccept: false, 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   rcv_settle_mode: 1, 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   snd_settle_mode: 0, 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   source: { address: 'taskEmail' }, 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   credit_window: 0, 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   onMessage: [Function: onMessage], 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   onClose: [Function: onClose], 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   onSessionClose: [Function: onSessionClose], 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   onError: [Function], 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   onSessionError: [Function], 
Dec 12 12:57:01 listener-4 [deployment-77bdf658dd-4kfd7]   onSettled: [Function] } 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Session got event: session_open 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.018Z rhea-promise:translate [connection-2] Translating the context for event: 'session_open'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.019Z rhea-promise:receiver [connection-2] Added event handler for event 'message' on rhea-promise 'receiver'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.019Z rhea-promise:receiver [connection-2] Added event handler for event 'receiver_error' on rhea-promise 'receiver'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.019Z rhea-promise:receiver [connection-2] Added event handler for event 'receiver_close' on rhea-promise 'receiver'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.019Z rhea-promise:receiver [connection-2] Added event handler for event 'settled' on rhea-promise 'receiver'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: receiver_open 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.022Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_open'. Re-emitting the translated context. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.022Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_open'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.022Z rhea-promise:receiver [connection-2] Resolving the promise with amqp receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.022Z azure:service-bus:error [connection-2] Receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' has established itself. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Connection got event: disconnected 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.554Z rhea-promise:translate [connection-2] Translating the context for event: 'disconnected'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.555Z azure:service-bus:error [connection-2] state: { wasConnectionCloseCalled: false, numClients: 1 } 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.555Z azure:service-bus:error [connection-2] connection.close() was not called from the sdk and there were some clients. We should reconnect. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.856Z azure:service-bus:error [connection-2] calling detached on client 'taskEmail/168c1a36-4d5f-2144-9fbb-b3de2f581776'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.856Z azure:service-bus:error [connection-2] calling detached on streaming receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.856Z rhea-promise:error [connection-2] The receiver is open ? -> false 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.856Z rhea-promise:receiver [connection-2] receiver has been closed, now closing it's session. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.856Z rhea-promise:error [connection-2] The session is open ? -> false 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.857Z azure:service-bus:error [connection-2] close() method of Receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.857Z azure:service-bus:error [connection-2] Receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' is open? -> false 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.857Z azure:service-bus:error [connection-2] The receiver 'taskEmail-eaf3d482-cfa1-3f47-ae71-103d321adf6f' with address 'taskEmail' is not open and is not currently establishing itself. Hence let's try to connect. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Connection got event: connection_open 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.875Z rhea-promise:translate [connection-2] Translating the context for event: 'connection_open'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Session got event: session_open 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.877Z rhea-promise:translate [connection-2] Translating the context for event: 'session_open'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: sender_open 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.879Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_open'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: sender_flow 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.879Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_flow'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: sendable 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.879Z rhea-promise:translate [connection-2] Translating the context for event: 'sendable'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: receiver_open 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.881Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_open'. Re-emitting the translated context. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.882Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_open'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.882Z rhea-promise:receiver [connection-2] Resolving the promise with amqp receiver 'cbs-0af819c5-f5d1-3541-be3c-5e6ba2445be4'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Received disposition for outgoing transfers 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: accepted 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.942Z rhea-promise:translate [connection-2] Translating the context for event: 'accepted'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: settled 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.942Z rhea-promise:translate [connection-2] Translating the context for event: 'settled'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:02 GMT rhea:events [connection-2] Link got event: message 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.973Z rhea-promise:receiver [connection-2] receiver got event: 'message'. Re-emitting the translated context. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.973Z rhea-promise:translate [connection-2] Translating the context for event: 'message'. 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:02.974Z azure:service-bus:error [connection-2] Trying to create receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with options { name: 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376', 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   autoaccept: false, 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   rcv_settle_mode: 1, 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   snd_settle_mode: 0, 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   source: { address: 'taskEmail' }, 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   credit_window: 0, 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   onMessage: [Function: onMessage], 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   onClose: [Function: onClose], 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   onSessionClose: [Function: onSessionClose], 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   onError: [Function], 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   onSessionError: [Function], 
Dec 12 12:57:02 listener-4 [deployment-77bdf658dd-4kfd7]   onSettled: [Function] } 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:03 GMT rhea:events [connection-2] Session got event: session_open 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.040Z rhea-promise:translate [connection-2] Translating the context for event: 'session_open'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.040Z rhea-promise:receiver [connection-2] Added event handler for event 'message' on rhea-promise 'receiver'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.040Z rhea-promise:receiver [connection-2] Added event handler for event 'receiver_error' on rhea-promise 'receiver'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.040Z rhea-promise:receiver [connection-2] Added event handler for event 'receiver_close' on rhea-promise 'receiver'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.040Z rhea-promise:receiver [connection-2] Added event handler for event 'settled' on rhea-promise 'receiver'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 04:57:03 GMT rhea:events [connection-2] Link got event: receiver_open 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.043Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_open'. Re-emitting the translated context. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.043Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_open'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.043Z rhea-promise:receiver [connection-2] Resolving the promise with amqp receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376'. 
Dec 12 12:57:03 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T04:57:03.044Z azure:service-bus:error [connection-2] Receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail' has established itself. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Link got event: sender_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.105Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Link got event: sender_close 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.106Z rhea-promise:translate [connection-2] Translating the context for event: 'sender_close'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Link got event: receiver_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.106Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_error'. Re-emitting the translated context. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.106Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Link got event: receiver_close 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.106Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_close'. Re-emitting the translated context. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.106Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_close'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Session got event: session_close 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.107Z rhea-promise:translate [connection-2] Translating the context for event: 'session_close'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Link got event: receiver_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.107Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_error'. Re-emitting the translated context. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.107Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.108Z azure:service-bus:error [connection-2] An error occurred for Receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376': { ConnectionForcedError: The connection was inactive for more than the allowed 240000 milliseconds and is closed by container 'c19d66c99fe74b84ace1946f8630394b_G54'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Object.translate (/opt/nwc-task-svc/node_modules/@azure/amqp-common/dist/index.js:907:17) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Receiver.MessageReceiver._onAmqpError (/opt/nwc-task-svc/node_modules/@azure/service-bus/dist/index.js:2099:44) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Receiver.emit (events.js:198:13) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at emit (/opt/nwc-task-svc/node_modules/rhea-promise/dist/lib/util/utils.js:129:24) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Object.emitEvent (/opt/nwc-task-svc/node_modules/rhea-promise/dist/lib/util/utils.js:140:9) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Receiver._link.on (/opt/nwc-task-svc/node_modules/rhea-promise/dist/lib/link.js:252:25) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Receiver.emit (events.js:198:13) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Receiver.link.dispatch (/opt/nwc-task-svc/node_modules/rhea/lib/link.js:59:37) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Receiver.link.on_detach (/opt/nwc-task-svc/node_modules/rhea/lib/link.js:162:32) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Session.on_detach (/opt/nwc-task-svc/node_modules/rhea/lib/session.js:730:27) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Connection.(anonymous function) [as on_detach] (/opt/nwc-task-svc/node_modules/rhea/lib/connection.js:762:30) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at c.dispatch (/opt/nwc-task-svc/node_modules/rhea/lib/types.js:910:33) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Transport.read (/opt/nwc-task-svc/node_modules/rhea/lib/transport.js:109:36) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at SaslClient.read (/opt/nwc-task-svc/node_modules/rhea/lib/sasl.js:300:26) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Connection.input (/opt/nwc-task-svc/node_modules/rhea/lib/connection.js:504:35) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSSocket.emit (events.js:198:13) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at addChunk (_stream_readable.js:287:12) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at readableAddChunk (_stream_readable.js:268:11) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSSocket.Readable.push (_stream_readable.js:223:10) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSWrap.onStreamRead [as _originalOnread] (internal/stream_base_commons.js:94:17) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSWrap.onread (/opt/nwc-task-svc/node_modules/async-listener/glue.js:188:31) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   name: 'ConnectionForcedError', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   translated: true, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   retryable: true, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   info: null, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   condition: 'amqp:connection:forced' }. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.108Z azure:service-bus:error [connection-2] Since received error is retryable, we will NOT notify the user's error handler. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Link got event: receiver_close 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.108Z rhea-promise:receiver [connection-2] receiver got event: 'receiver_close'. Re-emitting the translated context. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.108Z rhea-promise:translate [connection-2] Translating the context for event: 'receiver_close'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z azure:service-bus:error [connection-2] 'receiver_close' event occurred for receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail'. The associated error is: c { 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   value: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]    [ Typed { type: [TypeDesc], value: 'amqp:connection:forced' }, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      Typed { 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]        type: [TypeDesc], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]        value: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         'The connection was inactive for more than the allowed 240000 milliseconds and is closed by container \'c19d66c99fe74b84ace1946f8630394b_G54\'.' }, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      Typed { type: [TypeDesc], value: null } ] } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z azure:service-bus:receiver [connection-2] Clearing message renew lock timers for all the active messages. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z azure:service-bus:error [connection-2] 'receiver_close' event occurred on the receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z rhea-promise:error [connection-2] The receiver is open ? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Session got event: session_close 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z rhea-promise:translate [connection-2] Translating the context for event: 'session_close'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z azure:service-bus:receiver [connection-2] Clearing message renew lock timers for all the active messages. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z azure:service-bus:error [connection-2] 'session_close' event occurred on the session of receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.109Z rhea-promise:error [connection-2] The receiver is open ? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: connection_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.110Z rhea-promise:translate [connection-2] Translating the context for event: 'connection_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: connection_close 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.110Z rhea-promise:translate [connection-2] Translating the context for event: 'connection_close'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z rhea-promise:receiver [connection-2] receiver has been closed, now closing it's session. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z rhea-promise:error [connection-2] The session is open ? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z rhea-promise:receiver [connection-2] receiver has been closed, now closing it's session. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z rhea-promise:error [connection-2] The session is open ? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z azure:service-bus:error [connection-2] close() method of Receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail' was not called. There was an accompanying error and it is retryable. This is a candidate for re-establishing the receiver link. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z azure:service-bus:error [connection-2] Receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail' is open? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.111Z azure:service-bus:error [connection-2] The receiver 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376' with address 'taskEmail' is not open and is not currently establishing itself. Hence let's try to connect. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.113Z azure:service-bus:error [connection-2] close() method of Receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9' with address 'taskEmail' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.113Z azure:service-bus:error [connection-2] Receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9' with address 'taskEmail' is open? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.113Z azure:service-bus:error [connection-2] Receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9' with address 'taskEmail' is open? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.113Z azure:service-bus:error [connection-2] The receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9' with address 'taskEmail' is open -> false and is connecting -> true. Hence not reconnecting. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: protocol_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: protocol_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.114Z rhea-promise:translate [] Translating the context for event: 'protocol_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: protocol_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.115Z rhea-promise:translate [] Translating the context for event: 'protocol_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: protocol_error 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: disconnected 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.116Z rhea-promise:translate [connection-2] Translating the context for event: 'disconnected'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.116Z azure:service-bus:error [connection-2] Error (context.error) occurred on the amqp connection: { [ProtocolError: Invalid protocol header for AMQP    ] 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   message: 'Invalid protocol header for AMQP \u0000\u0000\u0000\u0011', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   name: 'ProtocolError' } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.116Z rhea-promise:error [connection-2] Error occurred while establishing amqp connection: { [ProtocolError: Invalid protocol header for AMQP    ] 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   message: 'Invalid protocol header for AMQP \u0000\u0000\u0000\u0011', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   name: 'ProtocolError' } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.117Z azure:service-bus:error [connection-2] state: { wasConnectionCloseCalled: false, numClients: 1 } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.117Z azure:service-bus:error [connection-2] connection.close() was not called from the sdk and there were some clients. We should reconnect. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.117Z azure:service-bus:error [connection-2] An error occured while creating the receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9': { [MessagingError: Invalid protocol header for AMQP    ] name: 'MessagingError', translated: true, retryable: true } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.117Z rhea-promise:translate [] Translating the context for event: 'protocol_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.117Z rhea-promise:translate [] Translating the context for event: 'protocol_error'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] Thu, 12 Dec 2019 05:01:02 GMT rhea:events [connection-2] Connection got event: disconnected 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.128Z rhea-promise:translate [connection-2] Translating the context for event: 'disconnected'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.128Z azure:service-bus:error [connection-2] Error (context.error) occurred on the amqp connection: Error [ERR_STREAM_WRITE_AFTER_END]: write after end 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at writeAfterEnd (_stream_writable.js:248:12) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSSocket.Writable.write (_stream_writable.js:296:5) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Transport.write (/opt/nwc-task-svc/node_modules/rhea/lib/transport.js:56:16) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at SaslClient.write (/opt/nwc-task-svc/node_modules/rhea/lib/sasl.js:294:31) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Connection.output (/opt/nwc-task-svc/node_modules/rhea/lib/connection.js:461:28) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at /opt/nwc-task-svc/node_modules/rhea/lib/sasl.js:254:33 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at AnonymousClient.start (/opt/nwc-task-svc/node_modules/rhea/lib/sasl.js:102:5) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at SaslClient.on_sasl_mechanisms (/opt/nwc-task-svc/node_modules/rhea/lib/sasl.js:244:24) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at c.dispatch (/opt/nwc-task-svc/node_modules/rhea/lib/types.js:910:33) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Transport.read (/opt/nwc-task-svc/node_modules/rhea/lib/transport.js:109:36) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at SaslClient.read (/opt/nwc-task-svc/node_modules/rhea/lib/sasl.js:302:31) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at Connection.input (/opt/nwc-task-svc/node_modules/rhea/lib/connection.js:504:35) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSSocket.emit (events.js:198:13) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at addChunk (_stream_readable.js:287:12) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at readableAddChunk (_stream_readable.js:268:11) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSSocket.Readable.push (_stream_readable.js:223:10) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSWrap.onStreamRead [as _originalOnread] (internal/stream_base_commons.js:94:17) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]     at TLSWrap.onread (/opt/nwc-task-svc/node_modules/async-listener/glue.js:188:31) 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.128Z azure:service-bus:error [connection-2] state: { wasConnectionCloseCalled: false, numClients: 1 } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.129Z azure:service-bus:error [connection-2] connection.close() was not called from the sdk and there were some clients. We should reconnect. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.417Z azure:service-bus:error [connection-2] calling detached on client 'taskEmail/168c1a36-4d5f-2144-9fbb-b3de2f581776'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.417Z azure:service-bus:error [connection-2] calling detached on streaming receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.418Z rhea-promise:error [connection-2] The receiver is open ? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.418Z rhea-promise:receiver [connection-2] receiver has been closed, now closing it's session. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.418Z rhea-promise:error [connection-2] The session is open ? -> false 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.418Z azure:service-bus:error [connection-2] Something went wrong. State of Receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9' with address 'taskEmail' is: { wasCloseInitiated: true, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   receiverError: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]    { ProtocolError: Invalid protocol header for AMQP     
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      message: 'Invalid protocol header for AMQP \u0000\u0000\u0000\u0011', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      name: 'ProtocolError' }, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]   _receiver: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]    Receiver { 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      _events: [Object: null prototype] {}, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      _eventsCount: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      _maxListeners: undefined, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      actionInitiated: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      type: 'receiver', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      _session: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]       Session { 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _events: [Object: null prototype] {}, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _eventsCount: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _maxListeners: undefined, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         actionInitiated: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _connection: [Connection], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _session: [Session] }, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      _link: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]       Receiver { 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         session: [Session], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         connection: [Connection], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         name: 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         options: [Object], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         state: [EndpointState], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         issue_flow: true, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         local: [Object], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         remote: [Object], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         delivery_count: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         credit: 4, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         observers: [EventEmitter], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         drain: false, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _events: [Object], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         _eventsCount: 7 }, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]      linkOptions: 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]       { name: 'taskEmail-961265f2-91d8-cf43-8b1c-1f7c9280a376', 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         autoaccept: false, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         rcv_settle_mode: 1, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         snd_settle_mode: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         source: [Object], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         credit_window: 0, 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         onMessage: [Function: onMessage], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         onClose: [Function: onClose], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         onSessionClose: [Function: onSessionClose], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         onError: [Function], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         onSessionError: [Function], 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7]         onSettled: [Function] } } } 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.429Z azure:service-bus:error [connection-2] calling detached on client 'taskEmail/168c1a36-4d5f-2144-9fbb-b3de2f581776'. 
Dec 12 13:01:02 listener-4 [deployment-77bdf658dd-4kfd7] 2019-12-12T05:01:02.430Z azure:service-bus:error [connection-2] calling detached on streaming receiver 'taskEmail-fe8433f4-652b-7f4e-ad0c-231f6f0d8dd9'. ```

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 19 (9 by maintainers)

Most upvoted comments

If anyone is interested, here is the changelog for 1.1.6

+2
ramya-rao-a on Apr 24, 2020
Read more comments on GitHub
← azure-sdk-for-js: SentimentResponse is missing SentimentBatchResult type
azure-sdk-for-js: [Service Bus] Attempt to settle msg after session lock expiry yields unhelpful error messages →