You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by akabhishek1 <ma...@gmail.com> on 2020/11/12 17:14:15 UTC

qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Hi Team,

We are getting "Suspected deadlocked threads" error in PROD environment. We
are trying to find out root cause of this issue.

Could you please give us any clue regarding below error, so we can proceed
further.

Logs - 
Suspected deadlocked threads: JmsSession
[ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:10] delivery dispatcher
Id=41620240 is in BLOCKED on lock=org.mule.servicebus.SbusConnector@58e4b68c    
is owned by JmsSession [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:7]
delivery dispatcher Id=41620237 | JmsSession
[ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:7] delivery dispatcher
Id=41620237 is in WAITING on
lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
owned by JmsSession [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:5] delivery
dispatcher Id=41620235 | JmsSession
[ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:5] delivery dispatcher
Id=41620235 is in BLOCKED on lock=org.mule.servicebus.SbusConnector@58e4b68c    
is owned by JmsSession [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:7]
delivery dispatcher Id=41620237 | 


Regards,
Abhishek Kumar



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Thanks a lot for details reply.

We have added story in our backlog to upgrade project with 0.55.0 client. As
we have to do a lot of performance testing, so we will use latest version
for testing which will save our time. 

As you are targeting to release this week, so we will wait for release and
then plan to upgrade accordingly.

Thanks again.

Regards,
Abhishek Kumar



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Thanks for confirmation. It means QPID client will receive bad message at
only one time.

Can you please suggest - How can we identify that Queue have bad messages ?

In Production environment - If we have 1000 messages, and 100 messages are
bad messages. Support team needs to identify bad message, so they can take
action accordingly.

We need to have some mechanism to know bad messages otherwise it will be
very difficult for support person. 

Could you please suggest your opinion to handle this scenario.

Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
It isn't a defect. The behaviour was changed along with the original
improvements made way back in May after your original report.

On Tue, 22 Dec 2020 at 15:39, akabhishek1
<ma...@gmail.com> wrote:
>
> Hey Robbie,
>
> I want to provide you one more input regarding above issue. Just now, I
> tested with old Qpid Library 0.45.0 and it is working as expected.
>
> Old Qpid library (0.45.0) continuously receiving bad message. It seems like
> a defect in latest library(0.56.0).
>
> Please take a look and let me know for any query.
>
> Regards,
> Abhishek Kumar
>
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hey Robbie,

I want to provide you one more input regarding above issue. Just now, I
tested with old Qpid Library 0.45.0 and it is working as expected.

Old Qpid library (0.45.0) continuously receiving bad message. It seems like
a defect in latest library(0.56.0).

Please take a look and let me know for any query.

Regards,
Abhishek Kumar





--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
On Wed, 23 Dec 2020 at 13:24, akabhishek1
<ma...@gmail.com> wrote:
>
> Hey Robbie,
>
> Thanks a lot for details !!
>
> Yes messages are sending back to ServiceBus and Delivery Count is also
> increasing at first time. I was worried that why client is not reciving
> message again and how we will identify them. You pointed correctlly about
> deposition, I looked again bad messages in ServiceBus explorer and realized
> that all the bad messages are in Defferred state, So Client will not receive
> those messages due to Defferred state and will stay idle on broker.
>
>
> We need your input on below open questions to handle defer scenarion -
>
> 1. We are getting exception directly on 'onException' method where we don't
> have any details of JMS Message.
>
>    Can you please guide us - how can we extract Message details of bad
> messages like - Message ID, Sequence NO, queue name ?
>    Can we get hold of JMSMessage object? It will be so great if we can get
> hold it, so we can reject/abandon message.
>

The issue revolves around the message failing to be processed for
delivery, so it isn't available to access when the exception listener
fires.

> 2. As per microsoft
> (https://docs.microsoft.com/en-us/azure/service-bus-messaging/message-deferral),
> we can receive deferred message with the use of only Sequence Number.
>         Do we have any option to receive deferred message with Qpid Client? It will
> be great for reconciliation.

I dont know about this Service Bus functionality so I have no idea.

> 3. Do we have any option to control Disposition? So for example we can
> specify deadletter rather than defer.

The behaviour in this [rather irregular] case isnt controllable.

> 4. What is the disposition/delivery state set by qpid, that causes it to
> appear as deferred in Azure Service Bus?
>

As your logs show and I copied+noted in the previous reply, the client
sent a modified disposition with delivery-failed and
undeliverable-here flags set.




>
> Regards,
> Abhishek Kumar
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hey Robbie,

Thanks a lot for details !!

Yes messages are sending back to ServiceBus and Delivery Count is also
increasing at first time. I was worried that why client is not reciving
message again and how we will identify them. You pointed correctlly about
deposition, I looked again bad messages in ServiceBus explorer and realized
that all the bad messages are in Defferred state, So Client will not receive
those messages due to Defferred state and will stay idle on broker. 


We need your input on below open questions to handle defer scenarion - 

1. We are getting exception directly on 'onException' method where we don't
have any details of JMS Message.
   
   Can you please guide us - how can we extract Message details of bad
messages like - Message ID, Sequence NO, queue name ?
   Can we get hold of JMSMessage object? It will be so great if we can get
hold it, so we can reject/abandon message.

2. As per microsoft
(https://docs.microsoft.com/en-us/azure/service-bus-messaging/message-deferral),
we can receive deferred message with the use of only Sequence Number.
	Do we have any option to receive deferred message with Qpid Client? It will
be great for reconciliation.  
3. Do we have any option to control Disposition? So for example we can
specify deadletter rather than defer.
4. What is the disposition/delivery state set by qpid, that causes it to
appear as deferred in Azure Service Bus? 


Regards,
Abhishek Kumar



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
On Tue, 22 Dec 2020 at 16:54, akabhishek1
<ma...@gmail.com> wrote:
>
> I waited upto 30m still, but still application does not recived bad messages.
> After that I published one good message and application received it
> immediately.
>
> I can see that message delivery count is not increasing, it means QPID
> client is not touching to bad messages at all.

No, it really doesn't mean that. Here is the bit in your own earlier
logs showing the client getting your first 'bad message' transfer from
the server, then we know failing to get as far as firing onMessage
with it, and then the client sends a disposition explicitly telling
the server it has failed to deliver it (which is itself specifically
indicating to increment the delivery count) and also not to send it to
this same consumer (it is free to send it to others):

TRACE 2020-12-22 13:31:55,457 [AmqpProvider
:(1):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [994173375:1] RECV:
Transfer{handle=0, deliveryId=0,
deliveryTag=W\xb43M;ae@\xaa\x03\xefd\x94}|\xf8, messageFormat=0,
settled=null, more=false, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=true} (5332)
"\x00Sp\xc0\x06\x05A@@@C\x00Sq\xc1$\x02\xa3\x10x-opt-lock-token\x98M3\xb4Wa;@e\xaa\x03\xefd\x94}|\xf8\x00Sr\xc1\x9e\x0c\xa3\x0ex-opt-jms-destQ\x01\xa3\x12x-opt-jms-msg-typeQ\x05\xa3\x13x-opt-enqueued-time\x83\x00\x00\x01v\x8a\xa6.\x8d\xa3\x15x-opt-sequence-numberU\x02\xa3\x1dx-opt-enqueue-sequence-numberU\x00\xa3\x12x-opt-locked-until\x83\x00\x00\x01v\x8a\xa6\xa3\xcc\x00Ss\xc0h\x0d\xa1/ID:d687d444-a096-4bb6-998b-b7cfa66c7639:1:1:1-1@\xa1\x08test@@@\xa3\x18text/plain;charset=utf-8@@\x83\x00\x00\x01v\x8a\xa6.I@@@\x00Su\xb0\x00\x00\x13\x88\xc70\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
TRACE 2020-12-22 13:31:55,552 [AmqpProvider
:(1):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [994173375:1] SENT:
Disposition{role=RECEIVER, first=0, last=0, settled=true,
state=Modified{deliveryFailed=true, undeliverableHere=true,
messageAnnotations=null}, batchable=false}

What the server does with the message after that, the client has no
control over. You'll have to ask Microsoft.

>
> Please find attached log.  Latest_Logs.txt
> <http://qpid.2158936.n2.nabble.com/file/t396358/Latest_Logs.txt>

Nothing to see here really. As you already said, server sends message,
application consumes it.

>
> Regards,
> Abhishek Kumar
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
I waited upto 30m still, but still application does not recived bad messages. 
After that I published one good message and application received it
immediately.

I can see that message delivery count is not increasing, it means QPID
client is not touching to bad messages at all. 

Please find attached log.  Latest_Logs.txt
<http://qpid.2158936.n2.nabble.com/file/t396358/Latest_Logs.txt>  

Regards,
Abhishek Kumar



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
The client behaviour did change after 0.45.0, but it is not a defect.
The client now indicates the message not be redelivered to the
consumer because it can't handle it.

I have seen prior cases where ServiceBus apparently didnt make
messages available for delivery immediately 'because they are still
locked', even though the client has explicitly indicated it is
finished with the message, as your earlier logs show it did. Perhaps
if you wait it will be.

On Tue, 22 Dec 2020 at 16:25, akabhishek1
<ma...@gmail.com> wrote:
>
> Hey Robbie,
>
> Thanks a lot for quick reply. I did testing based on your suggestion.
> Application is not able to consume messages even after recreation of NEW JMS
> connection and consumer as well.
>
> Please find below comparison between "Qpid 0.56.0" and "Qpid 0.45.0" jar
>
> Qpid 0.56.0
> 1. Started Application
> 2. Published 10 bad messages
> 3. Application got exception on 'onException' method while consuming 10
> messages.  (Only first time – total 10 exception)
> 4. Application doesn't received any message/exception after that, even after
> exhaustion of lock duration, waited for couple of minutes
> 5. Restarted Application - NEW JMS Connection with New Consumer
> 6. Doesn't received any message/exception after restarting the application
> as well
> 7. I even retried to consume these messages with Old Qpid library 0.45.O as
> well, but application doesn't received that message as well.
>
> Qpid 0.45.0
> 1. Started Application
> 2. Published 10 bad messages
> 3. Application got exception on 'onException' method while consuming 10
> messages.
> 4. Continuously application receiving message/exception unless reached to
> max delivery count. Working as expected
>
> Please suggest your opinion on this issue.
>
> Regards,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hey Robbie,

Thanks a lot for quick reply. I did testing based on your suggestion.
Application is not able to consume messages even after recreation of NEW JMS
connection and consumer as well.

Please find below comparison between "Qpid 0.56.0" and "Qpid 0.45.0" jar

Qpid 0.56.0
1. Started Application
2. Published 10 bad messages
3. Application got exception on 'onException' method while consuming 10
messages.  (Only first time – total 10 exception)
4. Application doesn't received any message/exception after that, even after
exhaustion of lock duration, waited for couple of minutes
5. Restarted Application - NEW JMS Connection with New Consumer
6. Doesn't received any message/exception after restarting the application
as well
7. I even retried to consume these messages with Old Qpid library 0.45.O as
well, but application doesn't received that message as well.

Qpid 0.45.0
1. Started Application
2. Published 10 bad messages
3. Application got exception on 'onException' method while consuming 10
messages. 
4. Continuously application receiving message/exception unless reached to
max delivery count. Working as expected

Please suggest your opinion on this issue.

Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
Your expectation that it would be delivered continuously to the
consumer doesnt align with what happens. When the message doesnt make
it as far as onMessage, the client marks it as having failed delivery
and for it not to be redelivered to the same consumer. If you want it
to be delivered again to the application instance you would need
multiple consumers or to recreate the consumer or whole connection
when the exception listener fires.

On Tue, 22 Dec 2020 at 14:24, akabhishek1
<ma...@gmail.com> wrote:
>
> Hey Robbie,
>
> I was doing testing with 0.56.0 jar and I found one issue while consuming
> bad messages from ServiceBus.
>
> Issue - Application is not consuming bad message continuously.
>
> Steps -
> 1. Started Application (ServiceBus Message lock duration is 30seconds)
> 2. Published 10 bad messages
> 3. Application got exception on 'onException' method while consuming 10
> messages. Application logged exception and doesn't reconnected to JMS
> connection and receiver as both are connected.
> 4. Published 1 good message
> 5. Application successfully received good message. Which means receiver is
> connected and consuming messages.
> 6. Issue - As message lock duration is 30seconds, so application should
> receive bad message continuously (30 seconds) until reached to max
> DeliveryCount(10). But application hasn't received bad message after first
> attempt.
>
> Problem - As application doesn't receiving bad message continuously, so
> message is not moving in dead letter queue.
>
> I am not sure above issue belongs to Qpid or Microsoft. Could you please
> suggest your opinion on this issue.
>
> Please find attached log file and screenShot of message.
> Error_Logs_Not_Consuming_Continuously.txt
> <http://qpid.2158936.n2.nabble.com/file/t396358/Error_Logs_Not_Consuming_Continuously.txt>
> Message_ScreenShot.PNG
> <http://qpid.2158936.n2.nabble.com/file/t396358/Message_ScreenShot.PNG>
>
> Regards,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hey Robbie,

I was doing testing with 0.56.0 jar and I found one issue while consuming
bad messages from ServiceBus. 

Issue - Application is not consuming bad message continuously.

Steps - 
1. Started Application (ServiceBus Message lock duration is 30seconds)
2. Published 10 bad messages
3. Application got exception on 'onException' method while consuming 10
messages. Application logged exception and doesn't reconnected to JMS
connection and receiver as both are connected.
4. Published 1 good message
5. Application successfully received good message. Which means receiver is
connected and consuming messages.
6. Issue - As message lock duration is 30seconds, so application should
receive bad message continuously (30 seconds) until reached to max
DeliveryCount(10). But application hasn't received bad message after first
attempt.

Problem - As application doesn't receiving bad message continuously, so
message is not moving in dead letter queue. 

I am not sure above issue belongs to Qpid or Microsoft. Could you please
suggest your opinion on this issue.

Please find attached log file and screenShot of message.
Error_Logs_Not_Consuming_Continuously.txt
<http://qpid.2158936.n2.nabble.com/file/t396358/Error_Logs_Not_Consuming_Continuously.txt>  
Message_ScreenShot.PNG
<http://qpid.2158936.n2.nabble.com/file/t396358/Message_ScreenShot.PNG>  

Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
On Mon, 14 Dec 2020 at 19:42, akabhishek1
<ma...@gmail.com> wrote:
>
> Hi Robbie,
>
> I applied the changes in exception listener which will make sure to cleanup
> once instead of multiple times. After changes, I tested multiple times and
> it is working fine so far.
>
> As you mentioned before - "By pairing the invalid message causing failure
> before
> onMessage (which is really quite unexpected) with disconnecting the actual
> connection in full"
>
> Do we need to worry about this?
>

No, as it typically won't happen, and the change to your handling I
suggested means it also isn't an issue if it were to, as your testing
showed.

> I saw your release notification for 0.56, I am hoping you will release this
> within 1-2 days. So i will use released version.
>

It will be released once a vote is successfully completed. Votes take
at least 3 days, so currently it might emerge early on Thursday
evening (in Europe) if all goes well.


> Regards,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hi Robbie,

I applied the changes in exception listener which will make sure to cleanup
once instead of multiple times. After changes, I tested multiple times and
it is working fine so far.

As you mentioned before - "By pairing the invalid message causing failure
before
onMessage (which is really quite unexpected) with disconnecting the actual
connection in full"

Do we need to worry about this? 

I saw your release notification for 0.56, I am hoping you will release this
within 1-2 days. So i will use released version.

Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
HI Robbie,

Thanks a lot for quick feedback. I will raise this with Microsoft.

Regards,
Abhi



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
If I understand your description and code correctly, you create 4
consumers (each on their own session) per 'Service Bus subscription',
using 2 connections, each of which are used for 2 different subs. You
then did something on the server side for a single sub and expected
its related 4 consumers to close, but actually consumers for both subs
in use on the connection were closed.

The logs very clearly show (snippets below) Service Bus remotely
initiating closure of all 8 consumers on the connection in quick
succession, for both sub 3 and sub 4 on connection 2 (rather than sub
1 on connection 1 as mentioned in your description). If that isn't
what you expected based on what you did you will need to raise that
with Microsoft, it's again not a client issue but server-initiated
behaviour.

TRACE 2020-12-10 20:20:41,753 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:5] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790524:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:5:1:test2/subscriptions/sub4'
is force detached. Code: consumer(link10371). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00080ab0000028835fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub4, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,759 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:1] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790494:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:1:1:test2/subscriptions/sub3'
is force detached. Code: consumer(link10359). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00050ab0000028775fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub3, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,761 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:2] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790505:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:2:1:test2/subscriptions/sub3'
is force detached. Code: consumer(link10362). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00050ab00000287a5fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub3, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,762 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:6] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790529:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:6:1:test2/subscriptions/sub4'
is force detached. Code: consumer(link10374). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00080ab0000028865fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub4, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,764 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:3] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790510:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:3:1:test2/subscriptions/sub3'
is force detached. Code: consumer(link10365). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00050ab00000287d5fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub3, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,765 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:7] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790534:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:7:1:test2/subscriptions/sub4'
is force detached. Code: consumer(link10377). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00080ab0000028895fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub4, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,766 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:4] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790515:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:4:1:test2/subscriptions/sub3'
is force detached. Code: consumer(link10368). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00050ab0000028805fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub3, Timestamp:2020-12-10T20:20:41',
info=null}}
TRACE 2020-12-10 20:20:41,766 [AmqpProvider
:(2):[amqps://***.servicebus.windows.net:-1]]
org.apache.qpid.jms.provider.amqp.FRAMES: [1943855334:8] RECV:
Detach{handle=0, closed=true,
error=Error{condition=amqp:link:detach-forced, description='The link
'G7:1790539:qpid-jms:receiver:ID:25209b36-d040-48af-a4a1-3e21f090b3d0:1:8:1:test2/subscriptions/sub4'
is force detached. Code: consumer(link10380). Details:
InnerMessageReceiver was closed.
TrackingId:b77a844b00080ab00000288c5fd2830c_G7_B23,
SystemTracker:***:Topic:test2|sub4, Timestamp:2020-12-10T20:20:41',
info=null}}


On Thu, 10 Dec 2020 at 20:45, akabhishek1
<ma...@gmail.com> wrote:
>
> Hey Robbie,
>
> Thanks a lot for your suggestion. I am still working on exception listener,
> will let you know for any issue.
>
> While testing with 0.56.0-SNAPSHOT, I found one distinct issue - consumer
> closed for wrong receiver. Please find below details
>
> JMS Infra details -
> a) JMS Connection - 1
>    receiver endpoint - 2
>    Consumer on every receiver - 4 (Total 8)
>    Separate session for every consumer - Total 8
> b) JMS Connection - 1
>    receiver endpoint - 2
>    Consumer on every receiver - 4 (Total 8)
>    Separate session for every consumer - Total 8
>
> Steps to reproduce this issue -
> 1. Start attached MultipleConsumerTest.java class
> 2. disable only one receiver endpoint (only one subscription - sub1)
> 3. Wait for connection exception
> 4. We can see that two receivers are failing to consume messages which was
> registered on same JMS connection.
> As we have disabled only one subscription, so consumer should be close for
> only one receiver instead of two.
>
> Please find attached sample test class  MultipleConsumerTest.java
> <http://qpid.2158936.n2.nabble.com/file/t396358/MultipleConsumerTest.java>
> and error log  consumer_closed_for_wrong_receiver.txt
> <http://qpid.2158936.n2.nabble.com/file/t396358/consumer_closed_for_wrong_receiver.txt>
> . Please take a look on this issue and let us know your
> opinion.
>
>
> Regards,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hey Robbie,

Thanks a lot for your suggestion. I am still working on exception listener,
will let you know for any issue. 

While testing with 0.56.0-SNAPSHOT, I found one distinct issue - consumer
closed for wrong receiver. Please find below details

JMS Infra details -
a) JMS Connection - 1
   receiver endpoint - 2
   Consumer on every receiver - 4 (Total 8)
   Separate session for every consumer - Total 8
b) JMS Connection - 1
   receiver endpoint - 2
   Consumer on every receiver - 4 (Total 8)
   Separate session for every consumer - Total 8
   
Steps to reproduce this issue - 
1. Start attached MultipleConsumerTest.java class
2. disable only one receiver endpoint (only one subscription - sub1)
3. Wait for connection exception
4. We can see that two receivers are failing to consume messages which was
registered on same JMS connection. 
As we have disabled only one subscription, so consumer should be close for
only one receiver instead of two.
   
Please find attached sample test class  MultipleConsumerTest.java
<http://qpid.2158936.n2.nabble.com/file/t396358/MultipleConsumerTest.java>  
and error log  consumer_closed_for_wrong_receiver.txt
<http://qpid.2158936.n2.nabble.com/file/t396358/consumer_closed_for_wrong_receiver.txt> 
. Please take a look on this issue and let us know your 
opinion.


Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
On Wed, 9 Dec 2020 at 16:37, akabhishek1
<ma...@gmail.com> wrote:
>
> Hi Robbie,
>
> Thanks a lot for details insight and correction. Test case is working fine
> now with 0.56-SNAPSHOT.
> I am able to generate invalid message which continously throw 'Cannot decode
> String in UTF-8' error.
>
> The good thing is - I am able to generate "Suspected deadlocked threads"
> error repeatedly with Old(0.45.o) jar. I used invalid message .
>
> Steps to generate error - I need to do enable/disable queue and WiFI ON/OFF
> couple of times to get this error. I have not found consistent pattern yet,
> but couple of retries helps to generate this error.
>
> I did similar testing with New "0.56.0-SNAPSHOT" jar. Unfortunatelly I am
> getting same "Suspected deadlocked threads" error with new jar.
>

No, you are actually getting a fairly different scenario this time.
Previously the deadlock involved locks in your application and a
delivery lock within the client, which was being held when firing the
exception listener, and is also needed to close things down. We
removed that client lock from being in play here, which your result
shows is the case; your new result only involves locks outside the
client, within your application, but now being acquired in different
orders. By pairing the invalid message causing failure before
onMessage (which is really quite unexpected) with disconnecting the
actual connection in full, I think you managed to get multiple calls
to the exception listener. In those your handling then acquires these
application locks in different orders and thus upon which it can then
deadlock.

If your reaction to the ExceptionListener firing is always to close
the connection and reconnect, I would suggest that you use an
AtomicBoolean as a gate within your handler (which per previous mail,
should ensure it only operates on a single connection) such that only
a single attempt can be made to clear up and reconnect, thereby
removing the chance for your locks to be acquired in different orders,
e.g:

if (exceptionFired.compareAndSet(false, true)) {
  // Do cleanup work
}


> Can you please check attached thread dump
> "ThreadDumps_Deadlock_56-SNAPSHOT.txt", if you find anything from your side.
>
> ThreadDumps_Deadlock_56-SNAPSHOT.txt
> <http://qpid.2158936.n2.nabble.com/file/t396358/ThreadDumps_Deadlock_56-SNAPSHOT.txt>
>
> I am also trying to find root cause from my side.
>
> Regrads,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hi Robbie,

Thanks a lot for details insight and correction. Test case is working fine
now with 0.56-SNAPSHOT.
I am able to generate invalid message which continously throw 'Cannot decode
String in UTF-8' error.

The good thing is - I am able to generate "Suspected deadlocked threads"
error repeatedly with Old(0.45.o) jar. I used invalid message .

Steps to generate error - I need to do enable/disable queue and WiFI ON/OFF
couple of times to get this error. I have not found consistent pattern yet,
but couple of retries helps to generate this error. 

I did similar testing with New "0.56.0-SNAPSHOT" jar. Unfortunatelly I am
getting same "Suspected deadlocked threads" error with new jar.

Can you please check attached thread dump
"ThreadDumps_Deadlock_56-SNAPSHOT.txt", if you find anything from your side. 

ThreadDumps_Deadlock_56-SNAPSHOT.txt
<http://qpid.2158936.n2.nabble.com/file/t396358/ThreadDumps_Deadlock_56-SNAPSHOT.txt>  

I am also trying to find root cause from my side. 

Regrads,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
On Thu, 3 Dec 2020 at 18:36, akabhishek1
<ma...@gmail.com> wrote:
>
> Hi Robbie,
>
> Thanks for quick reply. I referenced your test case and tried to generate
> "Illegal invocation from MessageListener callback" error.
> At this moment, I am not able to generate this error neither "Suspected
> deadlocked threads" error.
>
> So, I can't confirm that this fix is working or not.
>
> Please find attached sample test class  ConnectionTest.java
> <http://qpid.2158936.n2.nabble.com/file/t396358/ConnectionTest.java>  . I
> tested with both library "45.0" and "0.56.0-SNAPSHOT", And test cases are
> failing for both jar versions.
> So definitely, I am missing something .

A few things.

You are trying to use the same invalid-payload my test uses, but you
are in fact sending something that is very different and perfectly
valid, so it presumably won't generate the TextMessage decode failure,
and be successfully received, failing the test. When you send a
BytesMessage with the client it is annotated as such, and will always
be treated as a BytesMessage on receipt, so that payload is perfectly
valid then. The client cant generate the exact payload I used in my
test. You might be able to directly replace the body Section on the
text message facade with some reflection to get closer to the same
payload.

You could also do what I said in my earlier mail and use larger
multi-frame messages with unicode characters. You could even reduce
the connections maxFrameSize to lower the threshold for multiple
frames being required to receive a message, causing more frames and
increasing the chance of the cross-frame decode issue in the old
client. The newer proton-j used in the new client wont throw that
failure though and so wont cause the delivery failure, you would have
to use dependency management to downgrade the new client to use e.g
0.33.7.

You look to be trying to perform essentially exactly the same test I
did. If you succeed it should of course give the same result. I was
expecting you to test what you are doing when you see the error,
having encountered two different ways of doing so.

You will certainly never reproduce the deadlock with the test as it
only has 1 connection/session rather than 2+ needed, and has no
application-level lock for them to compete over before trying to close
the others and form the block.

(It won't matter here, but I also noticed you have a somewhat amusing
and contradictory set of URI options:
"&jms.forceSyncSend=true&jms.forceAsyncSend=true"...sync wins due to
the impl).

>
> Is that possible for you to suggest correction in attached
> "ConnectionTest.java" ? So I can generate error and proceed further for
> testing.
>
> Regarding last reported 3 issues - I will try to replicate these issues in
> independent project and share details with you.

I dont see a need. The second of your points isn't an issue at all and
your expectation was simply wrong, again likely in large part due to
the misleading error description used by Service Bus. The others are
server side behaviours.

> As we are upgrading library, so we want to make sure that existing(0.45.0)
> positive functionalities should match with latest jar (0.56.SNAPSHOT).
>
>
> Regards,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hi Robbie,

Thanks for quick reply. I referenced your test case and tried to generate
"Illegal invocation from MessageListener callback" error. 
At this moment, I am not able to generate this error neither "Suspected
deadlocked threads" error.

So, I can't confirm that this fix is working or not.

Please find attached sample test class  ConnectionTest.java
<http://qpid.2158936.n2.nabble.com/file/t396358/ConnectionTest.java>  . I
tested with both library "45.0" and "0.56.0-SNAPSHOT", And test cases are
failing for both jar versions. 
So definitely, I am missing something .

Is that possible for you to suggest correction in attached
"ConnectionTest.java" ? So I can generate error and proceed further for
testing.

Regarding last reported 3 issues - I will try to replicate these issues in
independent project and share details with you.
As we are upgrading library, so we want to make sure that existing(0.45.0)
positive functionalities should match with latest jar (0.56.SNAPSHOT). 


Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
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
<ma...@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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
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.

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.
	
	***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.
	

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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
Not really, no. Having just done 0.55.0 (+ various other releases)
very recently I wasn't actually looking to do another imminently. I'll
probably just do it at some point it suits in the next couple of
weeks.

I might also wait for you to report back on your testing unless
something else more pressing comes up. Had you tried things out after
the improvement made ~6 months ago due to your initial report, or
again after your recent re-report before 0.55.0 was released, this
'new' (~4 years old probably) issue would have been found and fixed
already without need of yet another/specific release.

On Wed, 2 Dec 2020 at 15:08, akabhishek1
<ma...@gmail.com> wrote:
>
> Hi Robbie,
>
> Thanks a lot for detail reply. We have started testing with
> "0.56.0-SNAPSHOT" .
>
> Do we have any high level timeline to release "0.56.0" ? So we can plan
> accordigly.
>
> Regards,
> Abhishek Kumar
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hi Robbie, 

Thanks a lot for detail reply. We have started testing with
"0.56.0-SNAPSHOT" . 

Do we have any high level timeline to release "0.56.0" ? So we can plan
accordigly.

Regards,
Abhishek Kumar



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
The "Illegal invocation from MessageListener callback" issue looks to
be a distinct bug in the client. A MessageListener isnt normally
allowed to call close() on its session or connection, however the way
this restriction is implemented in the client means it is currently
also being applied incorrectly during the ExceptionListener callback
caused by these unusual failures during async dispatch. Essentially,
if your application didnt deadlock upon itself across different
sessions/connections in somewhat of a circle as youve seen, then it
could have instead hit this bug.

I have raised https://issues.apache.org/jira/browse/QPIDJMS-521 and
pushed an initial change with a test exposing the issue and an initial
fix resolving it. You can try it out by building yourself from
https://github.com/apache/qpid-jms or using a snapshot from
http://repository.apache.org/content/groups/snapshots/.

The order of your connection/consumer/session closures doesnt make
sense. If you close the connection as you do first, then the sessions
and their consumers/producers are implicity shut down and marked
closed. You can just close the connection in that case.

No, you needn't call setMessageListener(null) first if you do close a
consumer. You can just close the consumer, or its session, or
connection. The overall effect isnt much different - all routes would
wait on the delivery lock if needed before proceeding.

Setting the fields to null wont really affect cleanup beyond basic GC.
If there is a failure to cleanup and there are threads still running
they may keep doing so regardless. That mostly shouldnt be a
problem(besides obviously the associated resources) since the
connections would be largely independent outwith your application. One
thing to perhaps look at may be the way you create/use the
ExceptionListeners. It might be good to try and ensure each listener
can only reference specific objects it was created for, and cant for
example reference different objects created later over time, which are
perhaps being served by another listener also created later, such that
they cant cross-interact that way.

The original issue occurred due to unexpected failure during the work
surrounding onMessage callback, leading to the ExceptionListener being
fired. In the older client, this was done while holding the session
delivery lock, leading to interaction with your applications own lock
and connection/session usage as I've previously explained, or failing
that issue arising then instead it could then hit QPIDJMS-521. One
simple way the unexpected failure might occur was for message arriving
with a Data body section and having content-type indicating it
contained text, but the payload not decoding as such. This seemed to
be what you were saw originally. Another simple way presented recently
by PROTON-2097 was for an entirely valid UTF-8 encoded string type
containing multi-byte character encodings, to be received across
multiple transfer sections, such that a single multi-byte character
was split across different internal buffer sections. Simplest way for
the client to hit this, is likely to receive a > 2MB TextMessage (with
amqp-value body section containing string type) with body composed
entirely of multi-byte unicode characters, ensuring it breaches the
clients default maxFrameSize and will be in multiple chunks. There is
still an element of variability where it could work though, depending
on the other properties etc in the message shifting the relative
position of the body content such that a character isn't split across
different chunks.

Robbie

On Thu, 26 Nov 2020 at 17:13, akabhishek1
<ma...@gmail.com> wrote:
>
> Hi Robbie,
>
> We are trying to replicate this issue from our end, so we can confidently
> apply fix and roll out to all. We need some your input/help to replicate
> this issue.  It could be be some issue from my end, So I am trying to find
> trouble code as well. Sorry for many questions.
>
> In May, we had this issue due to bad Message which was published with .Net,
> but now we got issue due to normal messages as well.
>
> We are having this issue while restarting of ServiceBus connector restart
> (due to ServiceBus connectivity loss). I follow below steps for restart -
> -------------------------------------------
> 1. Closing and Nullifying JMS Objects
>
> a. Connection.close(),
>     Connection = null,
>
> b. MessageConsumer.setMessageListener(null); --> I think i am doing wrong
> here. I don't need to set null here, as i am closing on next step. What's
> your opinion?
>     MessageConsumer.close();
>     MessageConsumer=null;
>
> c. Session.close();
>    Session = null
> ------------------------------------------
> 2. Creating JMS Objects
>     a. Create Connection
>     b. Create Session
>     c. Create Consumer
> ------------------------------------------
> Q1. ) Could you please suggest if I am doing anything wrong while restarting
> of JMS Objects ?
>
> Q2. ) If we got any exception while closing Connection, Session, Consumer
> and Producer, then how can we make sure that Connection, Session, Consumer
> and Producer closed and clear successfully from system?
> Is it good practise set Null to JMS Objects after closing to make sure that
> JMS Objects are cleaned up properly?
> I want to make sure that JMS object and threads are clear from system
> properly before creating new connection, so it will not cause any issue
> while starting of JMS connection, Session, etc.
> Overall I feel that, this could be an issue with clearance/disposing of
> existing JMS Objects.
>
> Could you please suggest your opinion to handle gracefully for exception
> scenario while closing JMS Objects?
>
>
> Q3. ) We got  "Illegal invocation from MessageListener callback" error while
> closing Connection & Session, and then we started having "Suspected
> deadlocked threads" error.
>
> Could you please suggest any idea to generate "Illegal invocation from
> MessageListener callback" error ? It could be one of reason for deadlocked.
> If I am able to generate this error then I could generate deadlock error.
>
> It will be great help if you provide your opinion on above queries.
>
> Please find below error logs.
>
> Error Pattern 1 -
> "Failed to close connection - 'Illegal invocation from MessageListener
> callback'"
> "Stopping: 'null'. Object is: ServicebusMessageReceiver"
> "Failed to reset message listener on endpoint
> 'servicebus://topic:***/subscriptions/***' - 'The MessageConsumer was closed
> due to an unrecoverable error.' - 'class javax.jms.IllegalStateException'"
> "Suspected deadlocked threads: JmsSession
> [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:10] delivery dispatcher
> Id=41620240 is in BLOCKED on
> lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
> JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
> Id=51620937 | JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7]
> delivery dispatcher Id=51620937 is in WAITING on
> lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
> owned by JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery
> dispatcher Id=41620235 | JmsSession
> [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery dispatcher
> Id=41620235 is in BLOCKED on
> lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
> JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
> Id=51620937 | "
> "Suspected deadlocked threads: JmsSession
> [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:10] delivery dispatcher
> Id=41620240 is in BLOCKED on
> lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
> JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
> Id=51620937 | JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7]
> delivery dispatcher Id=51620937 is in WAITING on
> lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
> owned by JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery
> dispatcher Id=41620235 | JmsSession
> [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery dispatcher
> Id=41620235 is in BLOCKED on
> lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
> JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
> Id=51620937 | "
> "Suspected deadlocked threads: JmsSession
> [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:10] delivery dispatcher
> Id=41620240 is in BLOCKED on
> lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
> JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
> Id=51620937 | JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7]
> delivery dispatcher Id=51620937 is in WAITING on
> lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
> owned by JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery
> dispatcher Id=41620235 | JmsSession
> [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery dispatcher
> Id=41620235 is in BLOCKED on
> lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
> JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
> Id=51620937 | "
>
> Error Sample 2
> "Failed to close connection - 'Illegal invocation from MessageListener
> callback'"
> "Failed to close session - 'Illegal invocation from MessageListener
> callback'"
>
> Regards,
> Abhishek Kumar
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hi Robbie,

We are trying to replicate this issue from our end, so we can confidently
apply fix and roll out to all. We need some your input/help to replicate
this issue.  It could be be some issue from my end, So I am trying to find
trouble code as well. Sorry for many questions.

In May, we had this issue due to bad Message which was published with .Net,
but now we got issue due to normal messages as well. 

We are having this issue while restarting of ServiceBus connector restart
(due to ServiceBus connectivity loss). I follow below steps for restart -
-------------------------------------------
1. Closing and Nullifying JMS Objects

a. Connection.close(), 
    Connection = null,

b. MessageConsumer.setMessageListener(null); --> I think i am doing wrong
here. I don't need to set null here, as i am closing on next step. What's
your opinion?
    MessageConsumer.close();
    MessageConsumer=null;

c. Session.close();
   Session = null
------------------------------------------
2. Creating JMS Objects
    a. Create Connection
    b. Create Session
    c. Create Consumer
------------------------------------------
Q1. ) Could you please suggest if I am doing anything wrong while restarting
of JMS Objects ?

Q2. ) If we got any exception while closing Connection, Session, Consumer
and Producer, then how can we make sure that Connection, Session, Consumer
and Producer closed and clear successfully from system? 
Is it good practise set Null to JMS Objects after closing to make sure that
JMS Objects are cleaned up properly?
I want to make sure that JMS object and threads are clear from system
properly before creating new connection, so it will not cause any issue
while starting of JMS connection, Session, etc.
Overall I feel that, this could be an issue with clearance/disposing of
existing JMS Objects.

Could you please suggest your opinion to handle gracefully for exception
scenario while closing JMS Objects?


Q3. ) We got  "Illegal invocation from MessageListener callback" error while
closing Connection & Session, and then we started having "Suspected
deadlocked threads" error.

Could you please suggest any idea to generate "Illegal invocation from
MessageListener callback" error ? It could be one of reason for deadlocked.
If I am able to generate this error then I could generate deadlock error.

It will be great help if you provide your opinion on above queries.

Please find below error logs. 

Error Pattern 1 -
"Failed to close connection - 'Illegal invocation from MessageListener
callback'"
"Stopping: 'null'. Object is: ServicebusMessageReceiver"
"Failed to reset message listener on endpoint
'servicebus://topic:***/subscriptions/***' - 'The MessageConsumer was closed
due to an unrecoverable error.' - 'class javax.jms.IllegalStateException'"
"Suspected deadlocked threads: JmsSession
[ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:10] delivery dispatcher
Id=41620240 is in BLOCKED on
lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
Id=51620937 | JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7]
delivery dispatcher Id=51620937 is in WAITING on
lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
owned by JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery
dispatcher Id=41620235 | JmsSession
[ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery dispatcher
Id=41620235 is in BLOCKED on
lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
Id=51620937 | "
"Suspected deadlocked threads: JmsSession
[ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:10] delivery dispatcher
Id=41620240 is in BLOCKED on
lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
Id=51620937 | JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7]
delivery dispatcher Id=51620937 is in WAITING on
lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
owned by JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery
dispatcher Id=41620235 | JmsSession
[ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery dispatcher
Id=41620235 is in BLOCKED on
lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
Id=51620937 | "
"Suspected deadlocked threads: JmsSession
[ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:10] delivery dispatcher
Id=41620240 is in BLOCKED on
lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
Id=51620937 | JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7]
delivery dispatcher Id=51620937 is in WAITING on
lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
owned by JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery
dispatcher Id=41620235 | JmsSession
[ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:5] delivery dispatcher
Id=41620235 is in BLOCKED on
lock=org.mule.transport.servicebus.SbusConnector@58e4b68c     is owned by
JmsSession [ID:ge300959-71f8-8fff-9d61-0a3e6dc02b98:9:7] delivery dispatcher
Id=51620937 | "

Error Sample 2
"Failed to close connection - 'Illegal invocation from MessageListener
callback'"
"Failed to close session - 'Illegal invocation from MessageListener
callback'"

Regards,
Abhishek Kumar



--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
The 'dispatcher thread' is the session thread used to deliver messages
from receiver onMessage callbacks, 1 thread per session as mandated by
JMS. When a session is delivering to onMessage, that blocks certain
other operations on the session/connection from completing since a
delivery is in progress, as mandated by JMS. This is accomplished with
a lock.

You are essentially blocking these delivery threads upon both
additional locks in your application and to extent upon each other, in
a circle'ish sequence, by having dispatcher thread acquire a lock
inside your application, then performing operations with the thread
upon different connection/session that require that other sessions
delivery lock, which you can't get because the other session is also
trying to do a similar thing at the same time, but is unable to get
the lock in your application as the first session has it, resulting in
each waiting on the other to finish, which they then obviously can't.
That is not an issue in JmsSession but in your general use of the
client.

As I have said a couple of times, we did identify one thing in 0.45.0
back in May where the session thread would continue to hold this
delivery lock while the thread was firing the connection exception
listener during certain types of delivery failure. We improved that so
it stopped holding the lock here in early June. Thus upgrading your
client would resolve the specific issue you reported in May. That may
or may not be the very same issue you are reporting now since you are
still using the older client, or it may actually be two onMessage
calls performing the similar thread dance, which there is nothing the
client can do about.

Separately, we identified an issue in proton-j, which can lead to the
very style of delivery failure from your original report (though you
also identified your particular usage of Service Bus tooling resulted
in that behaviour, so it may also be unrelated). The proton-j 0.33.8
release fixing that is now available, and we will do a Qpid JMS 0.55.0
release using it soon (though you can manually update to use 0.33.8
with the existing 0.54.0 release already if so desired).

Robbie

On Tue, 17 Nov 2020 at 16:41, akabhishek1
<ma...@gmail.com> wrote:
>
> Hey Robbie,
>
> Thanks a lot for quick reply.
>
> We are using JmsSession for below purposes
> 1. Creating JMS messages
> 2. Creating producers for sending message
> 3. Creating consumers for receiving message
>
> Thread name "delivery dispatcher" suggests that there is an issue in
> consumer JmsSession. Could you please confirm this ?
>
> If you think there could be an issue in other processor like JmsMessage
> creation or publishing then please let me know. So I can try to find
> blocking thread.
>
> Regards,
> Abhishek Kumar
>
>
>
>
> --
> 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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by akabhishek1 <ma...@gmail.com>.
Hey Robbie,

Thanks a lot for quick reply.

We are using JmsSession for below purposes
1. Creating JMS messages
2. Creating producers for sending message
3. Creating consumers for receiving message

Thread name "delivery dispatcher" suggests that there is an issue in
consumer JmsSession. Could you please confirm this ? 

If you think there could be an issue in other processor like JmsMessage
creation or publishing then please let me know. So I can try to find
blocking thread.

Regards,
Abhishek Kumar




--
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


Re: qpid-jms-client-0.45 --> Suspected deadlocked threads - owned by JmsSession delivery dispatcher

Posted by Robbie Gemmell <ro...@gmail.com>.
This seems likely to be similar to the situation we discussed in May
[1]. You have the delivery thread from one session, which necessarily
holds its own session delivery lock while dispatching, in a situation
it is also holding application-level lock(s), while then trying to
perform operations on another connection/session that requires holding
its session delivery lock too, which that session is already
necessarily holding by its own message delivery thread during
delivery, which is in turn waiting on getting the same application
lock(s) held by the other session thread earlier, and so your
application has created a cross-session-inter-application block upon
itself.

There was a nuance to the earlier thread, in that one of the threads
involved was actually running the connection ExceptionListener at the
time due to an issue attempting delivery of the messages (which you
traced to happening with messages you did certain management
operations on), and was still holding the session delivery lock while
it was doing that. Though this wasn't a client bug, it was something
we could improve without issue by unlocking the delivery lock before
doing that, and we did this in the 0.52.0 release early in June.
Perhaps you should try using one of the newer releases instead of the
same older version as before.

There will also be another client release soon (perhaps next week),
0.55.0, after the next proton-j release is available, which will
contain a very nuanced buffer/string-decoding related fix to string
that could perhaps even have also been in play in your original issue.

[1] https://lists.apache.org/thread.html/r93536c9040b79931f1eee99ba4f721335f5d7b8991ac3dfc50bd7d55%40%3Cusers.qpid.apache.org%3E



On Thu, 12 Nov 2020 at 17:14, akabhishek1
<ma...@gmail.com> wrote:
>
> Hi Team,
>
> We are getting "Suspected deadlocked threads" error in PROD environment. We
> are trying to find out root cause of this issue.
>
> Could you please give us any clue regarding below error, so we can proceed
> further.
>
> Logs -
> Suspected deadlocked threads: JmsSession
> [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:10] delivery dispatcher
> Id=41620240 is in BLOCKED on lock=org.mule.servicebus.SbusConnector@58e4b68c
> is owned by JmsSession [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:7]
> delivery dispatcher Id=41620237 | JmsSession
> [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:7] delivery dispatcher
> Id=41620237 is in WAITING on
> lock=java.util.concurrent.locks.ReentrantLock$NonfairSync@26cc0a98     is
> owned by JmsSession [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:5] delivery
> dispatcher Id=41620235 | JmsSession
> [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:5] delivery dispatcher
> Id=41620235 is in BLOCKED on lock=org.mule.servicebus.SbusConnector@58e4b68c
> is owned by JmsSession [ID:de300758-71f8-4fff-9d51-0a3e6dc01b88:9:7]
> delivery dispatcher Id=41620237 |
>
>
> Regards,
> Abhishek Kumar
>
>
>
> --
> 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