Quantcast

Fwd: Deadlock caused by ActiveMQMessageConsumer.dispatch() due to onEvent invocation

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Fwd: Deadlock caused by ActiveMQMessageConsumer.dispatch() due to onEvent invocation

Facundo Darío Velazquez Santillán
Hi.
In Mule ESB,
I have detected a deadlock caused by the interaction between Spring and
ActiveMQ.
Basically, there are two execution chains that are causing the deadlock:

First Chain: when a Message arrives to the JMS Queue:

1) ActiveMQMessageConsumer.dispatch() gets the lock of
FifoMessageDispatchChannel.mutex.
2) ActiveMQMessageConsumer.dispatch() calls the onMessage() method without
releasing the lock.
3) onMessage Mule Implementation calls org.springframework.
SingleConnectionFactory$SharedConnectionInvocationHandler.invoke() because
It needs a toString of the used resource (in this case the connection) to
logging purposes.
3) in ToString() method,
org.springframework.SingleConnectionFactory.getConnection()
method is called and It takes the org.springframework.Single
ConnectionFactory.connectionMonitor lock to access to connection (that's a
shared resource).

Lock ordering in this chain:

FifoMessageDispatchChannel.mutex lock -> org.springframework.SingleC
onnectionFactory.connectionMonitor lock

Second Chain: when A reconnection-strategy is applied:

1) Mule stops the current connection calling org.springframework.Sin
gleConnectionFactory.localStop()
2) LocalStop takes the org.springframework.SingleConnectionFactory
.connectionMonitor lock.
3) After a chain of calls: FifoMessageDispatchChannel.stop() is called.
4) FifoMessageDispatchChannel.stop() takes the
FifoMessageDispatchChannel.mutex lock.

Lock Ordering in this case:

org.springframework.SingleConnectionFactory.connectionMonitor lock ->
FifoMessageDispatchChannel.mutex lock

As you can see, The chains don't take care about lock ordering, and It's
causing a deadlock.

I think the root problem is the invocation of the external implemented
method onEvent().
Calling the external implemented onEvent() method in the synchronized lock
can cause an unpredictable behaviour in lock ordering causing deadlock
issues.
I think It could be resolved if the lock is released before invoking
onEvent().
I would like to know their opinions about this case to report an issue if
It is necessary.

Thanks.
Cheers.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Fwd: Deadlock caused by ActiveMQMessageConsumer.dispatch() due to onEvent invocation

Tim Bain
This is definitely a bug, the question is whose bug it is (whose code
should change): ActiveMQ, Mule, Spring, or some combination of the three.

I looked in http://grepcode.com/file/repo1.maven.org/maven2/org.
springframework/spring-jms/3.0.0.RELEASE/org/springframework/jms/connection/
SingleConnectionFactory.java and I don't see the org.springframework.Single
ConnectionFactory.getConnection() method you referenced. What version of
Spring are you using?

You referenced a toString() method; where is that code? My initial reaction
based on what you've written is that although calling external code while
holding a lock isn't great (and we might want to change the code to not do
that), the most egregious problem is the fact that a toString() method is
doing something that involves acquiring a lock, and that's my first thought
for the best way to solve this immediate problem.

Tim

On Mar 10, 2017 4:11 PM, "Facundo Darío Velazquez Santillán" <
[hidden email]> wrote:

Hi.
In Mule ESB,
I have detected a deadlock caused by the interaction between Spring and
ActiveMQ.
Basically, there are two execution chains that are causing the deadlock:

First Chain: when a Message arrives to the JMS Queue:

1) ActiveMQMessageConsumer.dispatch() gets the lock of
FifoMessageDispatchChannel.mutex.
2) ActiveMQMessageConsumer.dispatch() calls the onMessage() method without
releasing the lock.
3) onMessage Mule Implementation calls org.springframework.
SingleConnectionFactory$SharedConnectionInvocationHandler.invoke() because
It needs a toString of the used resource (in this case the connection) to
logging purposes.
3) in ToString() method,
org.springframework.SingleConnectionFactory.getConnection()
method is called and It takes the org.springframework.Single
ConnectionFactory.connectionMonitor lock to access to connection (that's a
shared resource).

Lock ordering in this chain:

FifoMessageDispatchChannel.mutex lock -> org.springframework.SingleC
onnectionFactory.connectionMonitor lock

Second Chain: when A reconnection-strategy is applied:

1) Mule stops the current connection calling org.springframework.Sin
gleConnectionFactory.localStop()
2) LocalStop takes the org.springframework.SingleConnectionFactory
.connectionMonitor lock.
3) After a chain of calls: FifoMessageDispatchChannel.stop() is called.
4) FifoMessageDispatchChannel.stop() takes the
FifoMessageDispatchChannel.mutex lock.

Lock Ordering in this case:

org.springframework.SingleConnectionFactory.connectionMonitor lock ->
FifoMessageDispatchChannel.mutex lock

As you can see, The chains don't take care about lock ordering, and It's
causing a deadlock.

I think the root problem is the invocation of the external implemented
method onEvent().
Calling the external implemented onEvent() method in the synchronized lock
can cause an unpredictable behaviour in lock ordering causing deadlock
issues.
I think It could be resolved if the lock is released before invoking
onEvent().
I would like to know their opinions about this case to report an issue if
It is necessary.

Thanks.
Cheers.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Fwd: Deadlock caused by ActiveMQMessageConsumer.dispatch() due to onEvent invocation

Facundo Darío Velazquez Santillán
Excuse me, if I referenced a wrong method.
In SingleConnectionFactory$SharedConnectionInvocationHandler.invoke(), when
the toString method is called, through inflection is invoked
getConnection() method. You can see it here.
getConnection() method takes the monitor lock that is participating in the
deadlock. You can see it here.
I'm agree you, I think the faster way to solve the problem, it's avoiding
this toString() method in our logs. I'll take this way.
I also could report to Spring, That They are locking a resource to do a
toString, although I suspect the idea is to not log a null connection.
Finally, It would be great, if you could give a solution regarding to the
external onMessage() invocation without releasing the log, to avoid future
deadlocks.

Thanks for all.
Cheers.
Facundo.

2017-03-13 15:35 GMT-03:00 Tim Bain <[hidden email]>:

> This is definitely a bug, the question is whose bug it is (whose code
> should change): ActiveMQ, Mule, Spring, or some combination of the three.
>
> I looked in http://grepcode.com/file/repo1.maven.org/maven2/org.
> springframework/spring-jms/3.0.0.RELEASE/org/springframework
> /jms/connection/
> SingleConnectionFactory.java and I don't see the org.springframework.Single
> ConnectionFactory.getConnection() method you referenced. What version of
> Spring are you using?
>
> You referenced a toString() method; where is that code? My initial reaction
> based on what you've written is that although calling external code while
> holding a lock isn't great (and we might want to change the code to not do
> that), the most egregious problem is the fact that a toString() method is
> doing something that involves acquiring a lock, and that's my first thought
> for the best way to solve this immediate problem.
>
> Tim
>
> On Mar 10, 2017 4:11 PM, "Facundo Darío Velazquez Santillán" <
> [hidden email]> wrote:
>
> Hi.
> In Mule ESB,
> I have detected a deadlock caused by the interaction between Spring and
> ActiveMQ.
> Basically, there are two execution chains that are causing the deadlock:
>
> First Chain: when a Message arrives to the JMS Queue:
>
> 1) ActiveMQMessageConsumer.dispatch() gets the lock of
> FifoMessageDispatchChannel.mutex.
> 2) ActiveMQMessageConsumer.dispatch() calls the onMessage() method without
> releasing the lock.
> 3) onMessage Mule Implementation calls org.springframework.
> SingleConnectionFactory$SharedConnectionInvocationHandler.invoke() because
> It needs a toString of the used resource (in this case the connection) to
> logging purposes.
> 3) in ToString() method,
> org.springframework.SingleConnectionFactory.getConnection()
> method is called and It takes the org.springframework.Single
> ConnectionFactory.connectionMonitor lock to access to connection (that's a
> shared resource).
>
> Lock ordering in this chain:
>
> FifoMessageDispatchChannel.mutex lock -> org.springframework.SingleC
> onnectionFactory.connectionMonitor lock
>
> Second Chain: when A reconnection-strategy is applied:
>
> 1) Mule stops the current connection calling org.springframework.Sin
> gleConnectionFactory.localStop()
> 2) LocalStop takes the org.springframework.SingleConnectionFactory
> .connectionMonitor lock.
> 3) After a chain of calls: FifoMessageDispatchChannel.stop() is called.
> 4) FifoMessageDispatchChannel.stop() takes the
> FifoMessageDispatchChannel.mutex lock.
>
> Lock Ordering in this case:
>
> org.springframework.SingleConnectionFactory.connectionMonitor lock ->
> FifoMessageDispatchChannel.mutex lock
>
> As you can see, The chains don't take care about lock ordering, and It's
> causing a deadlock.
>
> I think the root problem is the invocation of the external implemented
> method onEvent().
> Calling the external implemented onEvent() method in the synchronized lock
> can cause an unpredictable behaviour in lock ordering causing deadlock
> issues.
> I think It could be resolved if the lock is released before invoking
> onEvent().
> I would like to know their opinions about this case to report an issue if
> It is necessary.
>
> Thanks.
> Cheers.
>
Loading...