qpid-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Robbie Gemmell <robbie.gemm...@gmail.com>
Subject Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher
Date Thu, 03 Dec 2020 16:37:13 GMT
To be clear I meant testing of the issue in question, rather than
debugging your application / use of Service Bus.

On Thu, 3 Dec 2020 at 13:32, akabhishek1
<mailbox.abhishek.kumar@gmail.com> wrote:
>
> Hi Robbie,
>
> Sure, I will be happy to provide you testing feedback.
>
> I was doing testing with "qpid-jms-client-0.56.0-SNAPSHOT" and
> "proton-j-0.33.8". So far I managed to found three issues.
> These issues are intermittent, however we can regenerate this issue in
> couple of retries. I manage to capture error with Qpid Traces. Please find
> below details.
>
> Infrastructure Details --> Created 2 JMS connection instance for testing.
> First JMS connection.
>  * 1 endpoint topic-subscription
>  * 4 consumer/listener
>
> Second JMS connection.
>  * 1 endpoint Queue
>  * 4 consumer/listener
>
> Steps to reproduce this issue -
> 1. Start the application, which should start listening on both endpoints
> with separate JMS connections
> 2. DO NOT publish any message for consumption
> 3. Keep Application idle for 5m or sometimes 20m. If you didn't get this
> issue then please restart the application couple of times
>
> **** Issue Details *****
> 1. Both JMS connection have one active listener, but still getting this
> error - 'The connection was inactive for more than the allowed 120000
> milliseconds and is closed by container
> '7A2E0A0515A9427F82D1ACF7F25A024D_G12'. [condition =
> amqp:connection:forced]' - 'class javax.jms.JMSException'
>
>  We shouldn't get this error as we have 1 active listener on both JMS
> connection. Please refer "Receiver_Timeout_120000_ms.txt" log file for more
> details.
>

Your logs show there was a consumer and Service Bus closed it, with a
rather misleading error description that "The connection was inactive
for more than the allowed 120000 milliseconds and is closed...". The
connection was not closed (and as a whole wasnt inactive for 120sec
either way), the receiver was.

ServiceBus has its own unique definitions and enforcements of being
idle. ServiceBus closing the consumer link because you aren't using it
is not a client issue.

> 2. Inconsistent JMS connection status while getting timeout error.
>     a) Connection Active for Receiver TimeOut -  If we are getting timeout
> error due to receiver then we can see that connection is active at time of
> exception. Refer "Receiver_Timeout_120000_ms.txt"
>
>    b) Connection InActive for No Session/Producer/Consumer -  Create a JMS
> connection which does not have any session/producer/consumer and keep
> application running.  We will get 60000ms idle timeout error after some
> time. Please refer below logs.
> We are using "JmsConnection.getClientID" to check connection status. Please
> refer below sample method 'isConnectionActive'.
>
> Problem - At receiver time out (a) connection is active, But at second
> scenario (b) connection is inactive.
> I think at both scenario connection should be inactive.
>

No, they shouldn't. In the first case, the connection was still open
as I noted above, hence it didn't behave like it isn't. In the latter
case, the connection as a whole got closed, and so reacted
accordingly.

>         ***Logs**
>         TRACE 2020-12-03 12:40:05,354 [AmqpProvider
> :(3):[amqps://***.servicebus.windows.net:-1]]
> org.apache.qpid.jms.provider.amqp.FRAMES: [1314740929:0] RECV:
> Close{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:8ac03af7d6794026ab3948b199e58a35_G5, SystemTracker:gateway5,
> Timestamp:2020-12-03T12:40:05', info=null}}
> TRACE 2020-12-03 12:40:05,364 [AmqpProvider
> :(3):[amqps://***.servicebus.windows.net:-1]]
> org.apache.qpid.jms.provider.amqp.FRAMES: [1314740929:0] SENT:
> Close{error=null}
> ERROR 2020-12-03 12:40:05,370 [QpidJMS Connection Executor:
> ID:a6cf63d9-4608-4643-8955-eee32e604674:1]
> org.mule.servicebus.SbusConnector: Connection exception, Reason 'The
> connection was inactive for more than the allowed 60000 milliseconds and is
> closed by container 'LinkTracker'.
> TrackingId:8ac03af7d6794026ab3948b199e58a35_G5, SystemTracker:gateway5,
> Timestamp:2020-12-03T12:40:05 [condition = amqp:connection:forced]' - 'class
> org.apache.qpid.jms.JmsConnectionRemotelyClosedException',
> isConnectionActive 'false'
>
> ****Sample Code ***
> protected boolean isConnectionActive() {
>         boolean connectionStatus = false;
>         try {
>             String clientID = getConnection().getClientID();
>             connectionStatus = true;
>         } catch (Exception e) {
>             connectionStatus = false;
>         }
>         return connectionStatus;
>     }
>
> 3. Use Case - We have 1 JMS connection, which will be used for publishing
> message.
>         We know that ServiceBus detach active connection link, if we don't have any
> active Producer/Consumer.
>         For avoiding this issue, we registered a timer which will periodically
> create/reset temporary Session+Producer instead of JMS connection. This
> solution help us to keep JMS connection live, so we don't need to reset JMS
> connection again and again. We haven't faced any issue so far with old
> client 0.45.0 jar.
>
>         After upgrading the JAR, we are facing intermittent issue while resetting
> Producer. Error Log - "Failed to reset temp producer -
> javax.jms.JMSException: The service was unable to process the request;"
>         Please refer "3rd_issue_Failed_To_Reset_Producer_Error.txt" for more
> details.
>

The server refused the producers link attach, with error indicating an
internal-error and description saying it wasnt able to process the
request and to try again. I dont see anything wrong in what the client
says its doing (which matches what it did previously), and the server
gives no useful reason why it failed. This seems like a transient
server failure of some kind.

>
> NOTE - We haven't faced above 3 issues with Old client 0.45.0 jar.
>
> Could you please advise us on above 3 issues. Please feel free to let me
> know for any other information.
>
> Receiver_Timeout_120000_ms.txt
> <http://qpid.2158936.n2.nabble.com/file/t396358/Receiver_Timeout_120000_ms.txt>
> 3rd_issue_Failed_To_Reset_Producer_Error.txt
> <http://qpid.2158936.n2.nabble.com/file/t396358/3rd_issue_Failed_To_Reset_Producer_Error.txt>
>
>
>
> --
> Sent from: http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Mime
View raw message