'The connection was inactive for more than the allowed 60000 milliseconds and is closed by container 'LinkTracker'

[ganeshth]

Describe the bug
This has already been addressed in issue #142 , but we are seeing it in azure-servicebus-2.0.0-preview2.jar Is it advisable to use a preview jar?
QueueClient is closing after running for sometime. Unable to receive any messages

To Reproduce
Extend the ISessionHandler and pass the created SendClient object as one of the argument. Send messages for every few(say 5) received messages.

Expected behavior
QueueClient(SendClient and ReceiveClient) to run forever without closing.

Observed behavior
There is intermittent message about timed out (although it was described as a warning in issue #142 )

Environment (please complete the following information):

• OS: RHEL & Windows 7 Professional
• SDK Version: azure-servicebus-2.0.0-PREVIEW-4.jar

Additional context
`07:39:56,561 WARN [com.microsoft.azure.servicebus.primitives.RequestResponseLink] (ReactorThread47745f63-e2ca-466b-83ba-909bd5a571a3) Internal receive link of requestresponselink to '$cbs' closed with error.: com.microsoft.azure.servicebus.primitives.ServiceBusException: Error{condition=amqp:connection:forced, description='The connection was inactive for more than the allowed 60000 milliseconds and is closed by container 'LinkTracker'. TrackingId:1fcf812f43b04aac86b2bdfe20577dc9_G10, SystemTracker:gateway7, Timestamp:9/13/2018 2:09:23 AM', info=null}
at com.microsoft.azure.servicebus.primitives.ExceptionUtil.toException(ExceptionUtil.java:113) [azure-servicebus-2.0.0-PREVIEW-4.jar:]
at com.microsoft.azure.servicebus.primitives.RequestResponseLink$InternalReceiver.onClose(RequestResponseLink.java:670) [azure-servicebus-2.0.0-PREVIEW-4.jar:]
at com.microsoft.azure.servicebus.amqp.BaseLinkHandler.processOnClose(BaseLinkHandler.java:68) [azure-servicebus-2.0.0-PREVIEW-4.jar:]
at com.microsoft.azure.servicebus.amqp.BaseLinkHandler.onLinkRemoteClose(BaseLinkHandler.java:42) [azure-servicebus-2.0.0-PREVIEW-4.jar:]
at org.apache.qpid.proton.engine.BaseHandler.handle(BaseHandler.java:176) [proton-j-0.28.0.jar:]
at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:108) [proton-j-0.28.0.jar:]
at org.apache.qpid.proton.reactor.impl.ReactorImpl.dispatch(ReactorImpl.java:324) [proton-j-0.28.0.jar:]
at org.apache.qpid.proton.reactor.impl.ReactorImpl.process(ReactorImpl.java:291) [proton-j-0.28.0.jar:]
at com.microsoft.azure.servicebus.primitives.MessagingFactory$RunReactor.run(MessagingFactory.java:559) [azure-servicebus-2.0.0-PREVIEW-4.jar:]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_144]

07:39:56,563 WARN [com.microsoft.azure.servicebus.primitives.RequestResponseLink] (ReactorThread47745f63-e2ca-466b-83ba-909bd5a571a3) Completing all pending requests with exception in request response link to $cbs
07:39:56,564 ERROR [com.microsoft.azure.servicebus.primitives.MessagingFactory] (ReactorThread47745f63-e2ca-466b-83ba-909bd5a571a3) Connection error. 'Error{condition=amqp:connection:forced, description='The connection was inactive for more than the allowed 60000 milliseconds and is closed by container 'LinkTracker'. TrackingId:1fcf812f43b04aac86b2bdfe20577dc9_G10, SystemTracker:gateway7, Timestamp:9/13/2018 2:09:23 AM', info=null}'
07:39:56,564 INFO [com.microsoft.azure.servicebus.primitives.MessagingFactory] (ReactorThread47745f63-e2ca-466b-83ba-909bd5a571a3) Closing connection to host
07:46:28,823 INFO [com.microsoft.azure.servicebus.MessageAndSessionPump] (Finalizer) Closing message and session pump on entity 'storageack'
07:46:28,825 INFO [com.microsoft.azure.servicebus.primitives.MessagingFactory] (ForkJoinPool.commonPool-worker-3) Closing messaging factory
07:46:28,825 INFO [com.microsoft.azure.servicebus.primitives.MessagingFactory] (ForkJoinPool.commonPool-worker-3) Closing CBS link
07:46:28,826 INFO [com.microsoft.azure.servicebus.primitives.RequestResponseLink] (ForkJoinPool.commonPool-worker-3) Closing requestresponselink to $cbs by closing both internal sender and receiver links.
07:46:28,827 INFO [com.microsoft.azure.servicebus.primitives.RequestResponseLinkCache] (ForkJoinPool.commonPool-worker-0) Closing all cached request-response links
07:46:28,829 INFO [com.microsoft.azure.servicebus.primitives.MessagingFactory] (ReactorThread47745f63-e2ca-466b-83ba-909bd5a571a3) Gracefully releasing reactor thread as messaging factory is closed
07:46:28,829 INFO [com.microsoft.azure.servicebus.primitives.MessagingFactory] (ReactorThread47745f63-e2ca-466b-83ba-909bd5a571a3) Stopping reactor`

[ganeshth]

Hi @yvgopal sorry for the delay. This is the new issue which I opened and also Issue seems to be intermittent and we are seeing it only on few systems. Seems like issue with the jar used. Is it advisable to use a Preview jar?

Following are the answers for your comments from previous issue #142 :
What is the SDK version you are using? I would advise the latest version as we fixed a bug in 1.2.6.
azure-servicebus-2.0.0-PREVIEW-4.jar
What is your use case? When do you see this error?
We are extending the ISessionHandler and passing SendClient object as one of the argument. There will be sending of messages for every few messages received within that onMessageAsync() method
Is your QueueClient creation successful?
yes
If your QueuClient creation is successful, "Closing messaging factory" trace tells me that you are closing the QueueClient yourself. Why?
There is no call to the close method, so we are not closing it

[axisc]

@ganeshth

If there is no action, the connection is automatically closed. However, the next connection will reconnect automatically.

What you are seeing are just the log statements detailing this behavior.

[ganeshth]

Hi

Closing connection to host is fine, but Stopping the reactor. Is it expected?

[axisc]

can you share the sample code for the repro?

[ganeshth]

Hi,

Sorry for the delay, I think the cause might be due to architecture difference of our application. We are checking it.

I can share the code based on that. Will keep you posted.

[yvgopal]

It has been open for sometime. I assume it is no longer an issue. So closing it now. If you still see the problem, you can reopen it.

[sergiaguilar]

Hi there!!

I have the same problem, and i don't want those lines in my log:

com.microsoft.azure.servicebus.primitives.ServiceBusException: Error{condition=amqp:connection:forced, description='The connection was inactive for more than the allowed 60000 milliseconds and is closed by container 'LinkTracker'. TrackingId:50e355b3ddbc4bb1b775ca128b31f462_G10, SystemTracker:gateway7, Timestamp:2019-02-28T08:55:00', info=null}

How can I solve this problem??

Thanks!

[yvgopal]

That log states that the service closed your connection as it was idle. The SDK must log it, as a WARN, to know what happened with the connection and links.

[sergiaguilar]

Thanks, i know that this is what is happening. But i would like to know if it's possible to not show this log...
Thanks

[marcioos]

I think it shouldn't be a WARN level log if it doesn't represent any issue or actionable fact. In our application logs it ended up just adding noise, making it harder to spot actual problems. We ended up turning off WARN level logs coming from the SDK.

[clouddna-au]

Hi @marcioos How did you disable the Sdk logs, I have tried the following in our function v2 host.json file:

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "Microsoft.Azure.ServiceBus": "Warning"
    }
  }
}

but it seems to have still shown up in App Insights as an exception

Exception details in AppInsights

Event time | 4/29/2020, 9:18:05 PM (Local time) |  
-- | -- | --
Message | The connection was inactive for more than the allowed 60000 milliseconds and is closed by container '1a1730de-04ab-4c67-9704-b106bb8873d9'. |  
Exception type | Microsoft.Azure.ServiceBus.ServiceBusException |  
Failed method | Microsoft.Azure.ServiceBus.Core.MessageReceiver+<OnReceiveAsync>d__86.MoveNext

[dazinator]

I am using Microsoft.Azure.ServiceBus package to listen to a queue in a .netcore 3.1 application.
I am seeing that the exception handler (provided when listening to messages) is being invoked - with this exception.
Reading the above - I am confused. Is this an exception or not? I currently log this exception because its surfaced as one.

 await queueClient.Listen(handleMessageDelegate, onExceptionDelegate),
            

[onlywithlad]

HI Team,

Can anyone please guide on same issue. As i am also facing the same issue - Microsoft.Azure.ServiceBus.ServiceBusException: The connection was inactive for more than the allowed 60000 milliseconds and is closed by container '9a467ca2-d058-4484-8c39-99e4842d3555'. I am using Microsoft.Azure.ServiceBus with latest version

[wuting5250]

HI Team,

Can anyone please guide on same issue. As i am also facing the same issue - Microsoft.Azure.ServiceBus.ServiceBusException: The connection was inactive for more than the allowed 60000 milliseconds and is closed by container '9a467ca2-d058-4484-8c39-99e4842d3555'. I am using Microsoft.Azure.ServiceBus with latest version

I am also having this problem. If reconnecting is normal, I don't want it showing up in my logs.

[Juansero29]

My company is also having this logs. We don't understand why this is logged as a "[Fatal]" error if this is just an information log when the service has been inactive for sometime. Please remove this log from Fatal and make it just warning or an information log!

[Eyshika]

When you see this error, do you just reconnect to ServiceBus and it solves ?

[MooyYang]

hi team,
We are suffering from this issue too. The log "Caused by: com.microsoft.azure.servicebus.amqp.AmqpException: The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'".
Is there any configurations like min-idle-connections for Azure Service Bus?

[Yashwnat-Patil]

hi team,
We are suffering from this issue too. The log "Caused by: com.microsoft.azure.servicebus.amqp.AmqpException: The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'".
Is there any configurations like min-idle-connections for Azure Service Bus?

[jeff-kenward]

We just went through this with microsoft at length and I was able to prove that they have not implemented AMQP 1.0 to spec.

If you are using SASL credentials, it will not recognize that your connection is 'active' and even if you are sending traffic or empty frames to keep the connection alive, it will close it regardless after 60000 and you have to reconnect.

Microsoft built a fix for us but they have decided not to go GA with it. You have to ask them for it and they will apply it to your specific eventhub namespace. The fix also only works if you use namespace level Shared Access Policies. It can't be at the Event Hub level.

[sharmando]

I am also affected by the issue described by Jeff, I would love to know their ETA on a GA fix. We will see to reach out to them for more info or to apply the fix in our specific eventhub. Thanks for sharing @jeff-kenward.
A simple workaround for now is to create the eventhub producer each time you want to publish a message. This is of course not ideal, but it should allow a program to work past the few minutes the producer lives for.