Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

EmissionException: Spec. Rule 1.3 encountered when trying to recover receiver. #24762

Closed
conniey opened this issue Oct 13, 2021 · 1 comment · Fixed by #27250
Closed

EmissionException: Spec. Rule 1.3 encountered when trying to recover receiver. #24762

conniey opened this issue Oct 13, 2021 · 1 comment · Fixed by #27250
Assignees
@anuchandy @conniey
Labels
amqp Label for tracking issues related to AMQP Azure.Core azure-core bug This issue requires a change to an existing behavior in the product in order to be resolved. Client This issue points to a problem in the data-plane of the library. pillar-reliability The issue is related to reliability, one of our core engineering pillars. (includes stress testing) Service Bus
Projects
Azure AMQP - Nickel
Milestone
Backlog

Comments

@conniey
Copy link
Member

conniey commented Oct 13, 2021 •
edited

Possibly related: : #24582

2021-09-22T16:06:19.3720000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] Error received from reactor provider.
2021-09-22T16:06:19.3720000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] onConnectionError connectionId[<entityName>], hostName[<namespace>], message[Starting new reactor], error[connectionId[<entityName>] IO Sink was interrupted before reactor closed.]
2021-09-22T16:06:19.3810000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] Retry #2. Transient error occurred. Retrying after 14575 ms.
2021-09-22T16:06:19.3810000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<entityName>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-22T16:06:19.3820000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<entityName>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-22T16:06:19.4060000Z ERROR --- [reactor.core.publisher.Operators] Operator called default onErrorDropped
reactor.core.Exceptions$ErrorCallbackNotImplemented: reactor.core.publisher.Sinks$EmissionException: Spec. Rule 1.3 - onSubscribe, onNext, onError and onComplete signaled to a Subscriber MUST be signaled serially.
Caused by: reactor.core.publisher.Sinks$EmissionException: Spec. Rule 1.3 - onSubscribe, onNext, onError and onComplete signaled to a Subscriber MUST be signaled serially.
	at reactor.core.publisher.InternalEmptySink.emitError(InternalEmptySink.java:76)
	at com.azure.core.amqp.implementation.ReactorDispatcher.signalWorkQueue(ReactorDispatcher.java:130)
	at com.azure.core.amqp.implementation.ReactorDispatcher.invoke(ReactorDispatcher.java:94)
	at com.azure.core.amqp.implementation.RequestResponseChannel.lambda$closeAsync$12(RequestResponseChannel.java:230)
	at reactor.core.publisher.MonoRunnable.subscribe(MonoRunnable.java:49)
	at reactor.core.publisher.Mono.subscribe(Mono.java:4338)
	at reactor.core.publisher.MonoSubscribeOn$SubscribeOnSubscriber.run(MonoSubscribeOn.java:126)
	at reactor.core.scheduler.WorkerTask.call(WorkerTask.java:84)
	at reactor.core.scheduler.WorkerTask.call(WorkerTask.java:37)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

More logs:

2021-09-21T22:26:32.1410000Z WARN --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onTransportError hostname[<hostname>], connectionId[<namespace>], error[connection aborted]
2021-09-21T22:26:32.1460000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] signal[connection aborted, errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A], isTransient[false], initiatedByClient[false]]: Disposing of ReactorConnection.
2021-09-21T22:26:32.1480000Z INFO --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onConnectionUnbound hostname[<hostname>], connectionId[<namespace>], state[CLOSED], remoteState[ACTIVE]
2021-09-21T22:26:32.1490000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] onLinkFinal connectionId[<namespace>], linkName[<linkname>]
2021-09-21T22:26:32.1500000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] linkCredits: '3', expectedTotalCredit: '3'
2021-09-21T22:26:32.1500000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Receive link endpoint states are closed. Requesting another.
2021-09-21T22:26:32.1500000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Requesting a new AmqpReceiveLink from upstream.
2021-09-21T22:26:32.1500000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] linkName[<linkname>] entityPath[<entityPath>]. Setting next AMQP receive link.
2021-09-21T22:26:32.1500000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Receive link endpoint states are closed. Requesting another.
2021-09-21T22:26:32.1500000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] prefetch: '3', requested: '1', linkCredits: '3', expectedTotalCredit: '3', queuedMessages:'0', creditsToAdd: '0', messageQueue.size(): '0'
2021-09-21T22:26:32.1510000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Link credits='3', Link credits to add: '0'
2021-09-21T22:26:32.1510000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Requesting a new AmqpReceiveLink from upstream.
2021-09-21T22:26:32.1510000Z ERROR --- [com.azure.core.amqp.implementation.ReactorSession] connectionId[<namespace>] sessionName[<entityPath>] entityPath[<entityPath>] linkName[<linkname>] Cannot create receive link from a closed session., errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A, PATH: <entityPath>]
2021-09-21T22:26:32.1800000Z INFO --- [com.azure.core.amqp.implementation.handler.SessionHandler] onSessionFinal connectionId[<namespace>], entityName[<entityPath>], condition[null], description[null]
2021-09-21T22:26:32.1810000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] onLinkFinal connectionId[<namespace>], linkName[cbs:sender]
2021-09-21T22:26:32.1820000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.1820000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.1820000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] onLinkFinal connectionId[<namespace>], linkName[cbs:receiver]
2021-09-21T22:26:32.1830000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.1830000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.1830000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.1840000Z INFO --- [com.azure.core.amqp.implementation.handler.SessionHandler] onSessionFinal connectionId[<namespace>], entityName[cbs-session], condition[null], description[null]
2021-09-21T22:26:32.1840000Z INFO --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onConnectionFinal connectionId[<namespace>] hostname[<hostname>] errorCondition[amqp:resource-limit-exceeded] errorDescription[local-idle-timeout expired]
2021-09-21T22:26:32.1850000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] Closing executor.
2021-09-21T22:26:32.1860000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.1870000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.1870000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.1870000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.1880000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.1880000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.1880000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.1890000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.1890000Z INFO --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onTransportClosed hostname[<hostname>], connectionId[<namespace>], error[connection aborted]
2021-09-21T22:26:32.1890000Z INFO --- [com.azure.core.amqp.implementation.handler.CustomIOHandler] onTransportClosed connectionId[<namespace>], hostname[<hostname>]
2021-09-21T22:26:32.1900000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2050000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2060000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2060000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2070000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2070000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2080000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2080000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2090000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2090000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2100000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2100000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2110000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2110000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2120000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2120000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2120000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2130000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2130000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2130000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2140000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2140000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2140000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2150000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2150000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2160000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2160000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2160000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2170000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2170000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2170000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2180000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2180000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2180000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2190000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2190000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2190000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2200000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2200000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2200000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2200000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2210000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:32.2220000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:32.2220000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<namespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:32.2230000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:32.2230000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:32.2240000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<namespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:32.2240000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:32.2240000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<namespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9000000Z WARN --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onTransportError hostname[<hostname>], connectionId[<otherNamespace>], error[connection aborted]
2021-09-21T22:26:35.9010000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] signal[connection aborted, errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A], isTransient[false], initiatedByClient[false]]: Disposing of ReactorConnection.
2021-09-21T22:26:35.9010000Z INFO --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onConnectionUnbound hostname[<hostname>], connectionId[<otherNamespace>], state[CLOSED], remoteState[ACTIVE]
2021-09-21T22:26:35.9020000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] onLinkFinal connectionId[<otherNamespace>], linkName[<otherLinkname>]
2021-09-21T22:26:35.9050000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Receive link endpoint states are closed. Requesting another.
2021-09-21T22:26:35.9050000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Requesting a new AmqpReceiveLink from upstream.
2021-09-21T22:26:35.9060000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] linkName[<otherLinkname>] entityPath[<otherEntityPath>]. Setting next AMQP receive link.
2021-09-21T22:26:35.9070000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] linkCredits: '3', expectedTotalCredit: '3'
2021-09-21T22:26:35.9070000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Receive link endpoint states are closed. Requesting another.
2021-09-21T22:26:35.9070000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] prefetch: '3', requested: '1', linkCredits: '3', expectedTotalCredit: '3', queuedMessages:'0', creditsToAdd: '0', messageQueue.size(): '0'
2021-09-21T22:26:35.9070000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Link credits='3', Link credits to add: '0'
2021-09-21T22:26:35.9080000Z ERROR --- [com.azure.core.amqp.implementation.ReactorSession] connectionId[<otherNamespace>] sessionName[<otherEntityPath>] entityPath[<otherEntityPath>] linkName[<otherLinkname>] Cannot create receive link from a closed session., errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A, PATH: <otherEntityPath>]
2021-09-21T22:26:35.9120000Z INFO --- [com.azure.core.amqp.implementation.handler.SessionHandler] onSessionFinal connectionId[<otherNamespace>], entityName[<otherEntityPath>], condition[null], description[null]
2021-09-21T22:26:35.9140000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusReceiveLinkProcessor] Requesting a new AmqpReceiveLink from upstream.
2021-09-21T22:26:35.9140000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] onLinkFinal connectionId[<otherNamespace>], linkName[cbs:sender]
2021-09-21T22:26:35.9150000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9150000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9150000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] onLinkFinal connectionId[<otherNamespace>], linkName[cbs:receiver]
2021-09-21T22:26:35.9170000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9170000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9170000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9200000Z INFO --- [com.azure.core.amqp.implementation.handler.SessionHandler] onSessionFinal connectionId[<otherNamespace>], entityName[cbs-session], condition[null], description[null]
2021-09-21T22:26:35.9210000Z INFO --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onConnectionFinal connectionId[<otherNamespace>] hostname[<hostname>] errorCondition[amqp:resource-limit-exceeded] errorDescription[local-idle-timeout expired]
2021-09-21T22:26:35.9210000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] Closing executor.
2021-09-21T22:26:35.9220000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9220000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9220000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9220000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9230000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9240000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9240000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9240000Z INFO --- [com.azure.core.amqp.implementation.handler.ConnectionHandler] onTransportClosed hostname[<hostname>], connectionId[<otherNamespace>], error[connection aborted]
2021-09-21T22:26:35.9240000Z INFO --- [com.azure.core.amqp.implementation.handler.CustomIOHandler] onTransportClosed connectionId[<otherNamespace>], hostname[<hostname>]
2021-09-21T22:26:35.9250000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9250000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9260000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9270000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9270000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9270000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9280000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9280000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9280000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9280000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9290000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9290000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9300000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9300000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9300000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9300000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9310000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9310000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9310000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9310000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9320000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9320000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9320000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9330000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9330000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9330000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9340000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9340000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9340000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9350000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9350000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9350000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9350000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9350000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9350000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9360000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9360000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9370000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9370000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9370000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9370000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9370000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9380000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9400000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9410000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9410000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9420000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9420000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9420000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9430000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9430000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9430000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9440000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9440000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9440000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9450000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9450000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9450000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9460000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9470000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9480000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9480000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9480000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9490000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9490000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9490000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9490000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9490000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9490000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9510000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9510000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9510000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9520000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9520000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9520000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9520000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9530000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9530000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9530000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9530000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9530000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9540000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9550000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9550000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9550000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9560000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9560000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9560000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9560000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9570000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9570000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9570000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9580000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9580000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9580000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9610000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9610000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9610000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9620000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9630000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9630000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9640000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9660000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9660000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9660000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.handler.SendLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Sender link was never active. Closing endpoint states.
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.handler.ReceiveLinkHandler] connectionId[<otherNamespace>] linkName[cbs] entityPath[$cbs] Receiver link was never active. Closing endpoint states.
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Channel is closed. Requesting upstream. 
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Connection not requested, yet. Requesting one.
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] connectionId[<otherNamespace>] entityPath[$cbs] linkName[cbs] Emitting new response channel.
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Setting next AMQP channel.
2021-09-21T22:26:35.9670000Z INFO --- [com.azure.core.amqp.implementation.RequestResponseChannel:$cbs] namespace[<otherNamespace>] entityPath[$cbs]: Next AMQP channel received, updating 1 current subscribers
2021-09-21T22:26:36.1900000Z INFO --- [com.azure.core.amqp.implementation.ReactorExecutor] connectionId[<namespace>], message[Processing all pending tasks and closing old reactor.]
2021-09-21T22:26:36.1900000Z INFO --- [com.azure.core.amqp.implementation.ReactorDispatcher] connectionId[<namespace>] Reactor selectable is being disposed.
2021-09-21T22:26:36.1900000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] Shutdown signal received from reactor provider.
2021-09-21T22:26:36.1900000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] onConnectionShutdown connectionId[<namespace>], hostName[<hostname>], message[Shutting down], shutdown signal[false]
2021-09-21T22:26:36.2100000Z ERROR --- [reactor.core.publisher.Operators] Operator called default onErrorDropped
reactor.core.Exceptions$ErrorCallbackNotImplemented: com.azure.core.amqp.exception.AmqpException: connection aborted, errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A]
Caused by: com.azure.core.amqp.exception.AmqpException: connection aborted, errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A]
	at com.azure.core.amqp.implementation.ExceptionUtil.toException(ExceptionUtil.java:85)
	at com.azure.core.amqp.implementation.handler.ConnectionHandler.notifyErrorContext(ConnectionHandler.java:325)
	at com.azure.core.amqp.implementation.handler.ConnectionHandler.onTransportError(ConnectionHandler.java:228)
	at org.apache.qpid.proton.engine.BaseHandler.handle(BaseHandler.java:191)
	at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:108)
	at org.apache.qpid.proton.reactor.impl.ReactorImpl.dispatch(ReactorImpl.java:324)
	at org.apache.qpid.proton.reactor.impl.ReactorImpl.process(ReactorImpl.java:291)
	at com.azure.core.amqp.implementation.ReactorExecutor.run(ReactorExecutor.java:86)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
2021-09-21T22:26:36.2150000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusConnectionProcessor] Retry #1. Transient error occurred. Retrying after 4511 ms.
2021-09-21T22:26:36.2220000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] onConnectionShutdown connectionId[<namespace>], hostName[<hostname>], message[Shutting down], shutdown signal[false]
2021-09-21T22:26:39.9350000Z INFO --- [com.azure.core.amqp.implementation.ReactorExecutor] connectionId[<otherNamespace>], message[Processing all pending tasks and closing old reactor.]
2021-09-21T22:26:39.9350000Z INFO --- [com.azure.core.amqp.implementation.ReactorDispatcher] connectionId[<otherNamespace>] Reactor selectable is being disposed.
2021-09-21T22:26:39.9360000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] Shutdown signal received from reactor provider.
2021-09-21T22:26:39.9360000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] onConnectionShutdown connectionId[<otherNamespace>], hostName[<hostname>], message[Shutting down], shutdown signal[false]
2021-09-21T22:26:39.9370000Z ERROR --- [reactor.core.publisher.Operators] Operator called default onErrorDropped
reactor.core.Exceptions$ErrorCallbackNotImplemented: com.azure.core.amqp.exception.AmqpException: connection aborted, errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A]
Caused by: com.azure.core.amqp.exception.AmqpException: connection aborted, errorContext[NAMESPACE: <hostname>. ERROR CONTEXT: N/A]
	at com.azure.core.amqp.implementation.ExceptionUtil.toException(ExceptionUtil.java:85)
	at com.azure.core.amqp.implementation.handler.ConnectionHandler.notifyErrorContext(ConnectionHandler.java:325)
	at com.azure.core.amqp.implementation.handler.ConnectionHandler.onTransportError(ConnectionHandler.java:228)
	at org.apache.qpid.proton.engine.BaseHandler.handle(BaseHandler.java:191)
	at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:108)
	at org.apache.qpid.proton.reactor.impl.ReactorImpl.dispatch(ReactorImpl.java:324)
	at org.apache.qpid.proton.reactor.impl.ReactorImpl.process(ReactorImpl.java:291)
	at com.azure.core.amqp.implementation.ReactorExecutor.run(ReactorExecutor.java:86)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
2021-09-21T22:26:39.9390000Z INFO --- [com.azure.messaging.servicebus.implementation.ServiceBusConnectionProcessor] Retry #1. Transient error occurred. Retrying after 4511 ms.
2021-09-21T22:26:39.9420000Z INFO --- [com.azure.core.amqp.implementation.ReactorConnection] onConnectionShutdown connectionId[<otherNamespace>], hostName[<hostname>], message[Shutting down], shutdown signal[false]
@conniey conniey added bug This issue requires a change to an existing behavior in the product in order to be resolved. Client This issue points to a problem in the data-plane of the library. Azure.Core azure-core amqp Label for tracking issues related to AMQP labels Oct 13, 2021
@conniey
Copy link
Member Author

conniey commented Oct 13, 2021

@SamuelBucheliZ I created another issue for your bug. This is likely a race condition we need to investigate further. It could possibly due to the number of requestresponsechannels we create during a retry.

@conniey conniey mentioned this issue Dec 1, 2021
Closed
3 tasks
@conniey conniey added this to To do (Event Hubs) in Azure AMQP - Nickel Jan 14, 2022
@ramya-rao-a ramya-rao-a added this to the Backlog milestone Jan 14, 2022
@ramya-rao-a ramya-rao-a added the pillar-reliability The issue is related to reliability, one of our core engineering pillars. (includes stress testing) label Jan 14, 2022
@conniey conniey mentioned this issue Feb 22, 2022
Merged
6 tasks
Azure AMQP - Nickel automation moved this from To do (Event Hubs) to Done Feb 23, 2022
This was referenced Feb 25, 2022
Closed
Closed
@github-actions github-actions bot locked and limited conversation to collaborators Apr 11, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@anuchandy anuchandy

@conniey conniey

Labels
amqp Label for tracking issues related to AMQP Azure.Core azure-core bug This issue requires a change to an existing behavior in the product in order to be resolved. Client This issue points to a problem in the data-plane of the library. pillar-reliability The issue is related to reliability, one of our core engineering pillars. (includes stress testing) Service Bus
Projects
No open projects
Azure AMQP - Nickel
Done
Milestone
Backlog
Development

Successfully merging a pull request may close this issue.

Fixes EmissionException when outputting endpoint states. conniey/azure-sdk-for-java
3 participants
@anuchandy @conniey @ramya-rao-a