You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@mina.apache.org by Guus der Kinderen <gu...@gmail.com> on 2022/12/09 09:02:14 UTC
New deadlock potential in MINA 2.2's SSLHandler
Hello,
I wonder if MINA 2.2.1 introduces a new potential for deadlock in its
SSLHandler implementation. Did something change there, as compared to MINA
2.1.3?
Since this upgrade, we consistently run into a thread deadlock. One of the
threads that is deadlocking is sending data to the peer, while the other is
processing data from the peer. The deadlock involves a MINA-based lock (in
SSLHandler), and a lock in our code (StreamManager), that is responsible
for recording what packets that are exchanged have been acknowledged by the
peer. The latter did not change, so I'm suspecting a change in SSLHandler.
The stack traces of two deadlocked threads are added to this email.
Kind regards,
Guus
"TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
java.lang.Thread.State: BLOCKED
- blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2 (owned by
socket_c2s_ssl-thread-2 id=78)
at org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
at org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
at
org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
at
org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
at
org.jivesoftware.openfire.net.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
at
org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
at
org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
at
org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
at
org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
at
org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
- locked org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
at
org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
at
org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
at
org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
at
org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
at
org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
at
org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
at java.base@11.0.17
/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base@11.0.17
/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base@11.0.17
/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base@11.0.17
/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
"socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
java.lang.Thread.State: BLOCKED
- blocked on
org.jivesoftware.openfire.streammanagement.StreamManager@7e024771 (owned by
TaskEngine-pool-3 id=40)
at
org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
at
org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
at
org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:223)
at
org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
at
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
at org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
- locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
at
org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
at org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
at
org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
at
org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
at
org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
Re: New deadlock potential in MINA 2.2's SSLHandler
Posted by Jonathan Valliere <jo...@emoten.com>.
Check my graphic in the previous email.
On Mon, Dec 12, 2022 at 3:53 AM Emmanuel Lécharny <el...@gmail.com>
wrote:
> Hi Guus,
>
> there is something missing in the stacck trace: the two threads are
> blocked on different monitors:
> * SSLHandlerG0@99f49e2 owned by socket_c2s_ssl-thread-2
> * StreamManager@7e024771 owned by TaskEngine-pool-3
>
> they are not related, they are not blocking each one other.
>
> Can you provide the full stack trace ?
>
> Thanks !
>
>
> On 09/12/2022 10:02, Guus der Kinderen wrote:
> > Hello,
> >
> > I wonder if MINA 2.2.1 introduces a new potential for deadlock in its
> > SSLHandler implementation. Did something change there, as compared to
> MINA
> > 2.1.3?
> >
> > Since this upgrade, we consistently run into a thread deadlock. One of
> the
> > threads that is deadlocking is sending data to the peer, while the other
> is
> > processing data from the peer. The deadlock involves a MINA-based lock
> (in
> > SSLHandler), and a lock in our code (StreamManager), that is responsible
> > for recording what packets that are exchanged have been acknowledged by
> the
> > peer. The latter did not change, so I'm suspecting a change in
> SSLHandler.
> >
> > The stack traces of two deadlocked threads are added to this email.
> >
> > Kind regards,
> >
> > Guus
> >
> >
> > "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> > java.lang.Thread.State: BLOCKED
> > - blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2 (owned
> by
> > socket_c2s_ssl-thread-2 id=78)
> > at
> org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> > at
> org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > at
> > org.jivesoftware.openfire.net
> .StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> > at
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> > at
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> > at
> >
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> > at
> >
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> > - locked
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > at
> >
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> > at
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> > at
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> > at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
> > at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
> > at
> >
> org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
> > at
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
> > at
> > org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
> > at java.base@11.0.17
> > /java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> > at java.base@11.0.17
> > /java.util.concurrent.FutureTask.run(FutureTask.java:264)
> > at java.base@11.0.17
> >
> /java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> > at java.base@11.0.17
> >
> /java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> >
> > "socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
> > java.lang.Thread.State: BLOCKED
> > - blocked on
> > org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> (owned by
> > TaskEngine-pool-3 id=40)
> > at
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
> > at
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
> > at
> > org.jivesoftware.openfire.net
> .StanzaHandler.process(StanzaHandler.java:223)
> > at
> >
> org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
> > at
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
> > at
> org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
> > - locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > at
> > org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
> > at org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
> > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> >
>
> --
> *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> T. +33 (0)4 89 97 36 50
> P. +33 (0)6 08 33 32 61
> emmanuel.lecharny@busit.com https://www.busit.com/
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
> For additional commands, e-mail: users-help@mina.apache.org
>
> --
CONFIDENTIALITY NOTICE: The contents of this email message and any
attachments are intended solely for the addressee(s) and may contain
confidential and/or privileged information and may be legally protected
from disclosure.
Re: New deadlock potential in MINA 2.2's SSLHandler
Posted by Emmanuel Lécharny <el...@gmail.com>.
Hi Guus,
indeed, this is what I was looking for.
So this thread (TaskEngine-pool-3) is locking the StreamManager class
(the synchrinized on streamManager) and the global StreamManager class
lock done by thread socket_c2s_ssl-thread-2 in the StreamManager.java
class, function validateClientAcknowledgement
private synchronized boolean validateClientAcknowledgement(long h) {
return h <= ( unacknowledgedServerStanzas.isEmpty() ?
clientProcessedStanzas.get() : unacknowledgedServerStanzas.getLast().x );
}
The stack trace is:
"socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
java.lang.Thread.State: BLOCKED
- blocked on
org.jivesoftware.openfire.streammanagement.StreamManager@7e024771 (owned
by TaskEngine-pool-3 id=40)
at
org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
at
org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
at
org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:223)
at
org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
at
org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
at
org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
at org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
- locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
Sothe deadlock in your code is on the StreamManager class.
On 20/12/2022 14:09, Guus der Kinderen wrote:
> Hi Emmanuel,
>
> I'm not sure if I understand what you're saying or asking. My email
> client doesn't do a great job of formatting all that code in the email
> either, which might add to the confusion.
>
> The code that you seem to refer to is here:
> https://github.com/igniterealtime/Openfire/blob/cd28f39c411a0faede6d04454caf865d1695928f/xmppserver/src/main/java/org/jivesoftware/openfire/session/LocalClientSession.java#L923-L932 <https://github.com/igniterealtime/Openfire/blob/cd28f39c411a0faede6d04454caf865d1695928f/xmppserver/src/main/java/org/jivesoftware/openfire/session/LocalClientSession.java#L923-L932>
>
> There is a lock that intends to ensure that the 'streammanager' (which
> keeps statistics on data sent, received and acknowledged) is not used
> while data is being sent over the outbound connection.
>
> Does that make sense and answer your question?
>
> Kind regards,
>
> Guus
>
> On Mon, Dec 19, 2022 at 4:00 AM Emmanuel Lécharny <elecharny@gmail.com
> <ma...@gmail.com>> wrote:
>
> Hi Guus,
>
> thanks for teh full stack trace.
>
> I've some concern about this blocked thread:
> "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> java.lang.Thread.State: BLOCKED
> - blocked on
> org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2 (owned by
> socket_c2s_ssl-thread-2 id=78)
> at
> org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> at
> org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> at
> org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> at
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> at
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> at
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> at
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> - locked
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> at
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> at
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> at
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> ...
>
>
> As you can see, there is a lock on a StreamManager instance following a
> call to org.jivesoftware.openfire.session.La
> <http://org.jivesoftware.openfire.session.La> ocalSession.process:
>
> public void process(Packet packet) {
> // Check that the requested packet can be processed
> if (canProcess(packet)) {
> // Perform the actual processing of the packet. This
> usually implies sending
> // the packet to the entity
> try {
> // Invoke the interceptors before we send the packet
>
> InterceptorManager.getInstance().invokeInterceptors(packet, this,
> false,
> false);
> deliver(packet);
> <<<-------------------------------------Here
>
> but I don't see why a lock is taken, unless I don't have the proper
> source code.
>
> Which version are you using when having this deadlock?
>
>
> On 14/12/2022 09:37, Guus der Kinderen wrote:
> > Hi Emmanuel,
> >
> > I was trying to be helpful by leaving out unimportant details, but I
> > seem to have messed up. A third thread is involved. I've now
> attached
> > the full thread dump to this email.
> >
> > Kind regards,
> >
> > Guus
> >
> >
> > On Mon, Dec 12, 2022 at 9:53 AM Emmanuel Lécharny
> <elecharny@gmail.com <ma...@gmail.com>
> > <mailto:elecharny@gmail.com <ma...@gmail.com>>> wrote:
> >
> > Hi Guus,
> >
> > there is something missing in the stacck trace: the two
> threads are
> > blocked on different monitors:
> > * SSLHandlerG0@99f49e2 owned by socket_c2s_ssl-thread-2
> > * StreamManager@7e024771 owned by TaskEngine-pool-3
> >
> > they are not related, they are not blocking each one other.
> >
> > Can you provide the full stack trace ?
> >
> > Thanks !
> >
> >
> > On 09/12/2022 10:02, Guus der Kinderen wrote:
> > > Hello,
> > >
> > > I wonder if MINA 2.2.1 introduces a new potential for
> deadlock in its
> > > SSLHandler implementation. Did something change there, as
> > compared to MINA
> > > 2.1.3?
> > >
> > > Since this upgrade, we consistently run into a thread
> deadlock.
> > One of the
> > > threads that is deadlocking is sending data to the peer, while
> > the other is
> > > processing data from the peer. The deadlock involves a
> MINA-based
> > lock (in
> > > SSLHandler), and a lock in our code (StreamManager), that is
> > responsible
> > > for recording what packets that are exchanged have been
> > acknowledged by the
> > > peer. The latter did not change, so I'm suspecting a change in
> > SSLHandler.
> > >
> > > The stack traces of two deadlocked threads are added to
> this email.
> > >
> > > Kind regards,
> > >
> > > Guus
> > >
> > >
> > > "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> > > java.lang.Thread.State: BLOCKED
> > > - blocked on
> org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > (owned by
> > > socket_c2s_ssl-thread-2 id=78)
> > > at
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> > > at
> >
> org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > > at
> > >
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > > at
> > > org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>
> > <http://org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>>.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> > > at
> > >
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> > > at
> > >
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> > > at
> > >
> >
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> > > at
> > >
> >
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> > > - locked
> > org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > > at
> > >
> >
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> > > at
> > >
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> > > at
> > >
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> > > at
> org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
> > > at
> org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
> > > at
> > >
> >
> org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
> > > at
> > >
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
> > > at
> > >
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
> > > at java.base@11.0.17
> > >
> >
> /java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> > > at java.base@11.0.17
> > > /java.util.concurrent.FutureTask.run(FutureTask.java:264)
> > > at java.base@11.0.17
> > >
> >
> /java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> > > at java.base@11.0.17
> > >
> >
> /java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> > > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> > >
> > > "socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
> > > java.lang.Thread.State: BLOCKED
> > > - blocked on
> > >
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > (owned by
> > > TaskEngine-pool-3 id=40)
> > > at
> > >
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
> > > at
> > >
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
> > > at
> > > org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>
> > <http://org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>>.StanzaHandler.process(StanzaHandler.java:223)
> > > at
> > >
> >
> org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
> > > at
> > >
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
> > > at
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
> > > - locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > > at
> > >
> >
> org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
> > > at
> org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
> > > at
> > >
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
> > > at
> > >
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
> > > at
> > >
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
> > > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> > >
> >
> > --
> > *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> > T. +33 (0)4 89 97 36 50
> > P. +33 (0)6 08 33 32 61
> > emmanuel.lecharny@busit.com <ma...@busit.com>
> <mailto:emmanuel.lecharny@busit.com
> <ma...@busit.com>>
> > https://www.busit.com/ <https://www.busit.com/>
> <https://www.busit.com/ <https://www.busit.com/>>
> >
> >
> ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
> <ma...@mina.apache.org>
> > <mailto:users-unsubscribe@mina.apache.org
> <ma...@mina.apache.org>>
> > For additional commands, e-mail: users-help@mina.apache.org
> <ma...@mina.apache.org>
> > <mailto:users-help@mina.apache.org
> <ma...@mina.apache.org>>
> >
>
> --
> *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> T. +33 (0)4 89 97 36 50
> P. +33 (0)6 08 33 32 61
> emmanuel.lecharny@busit.com <ma...@busit.com>
> https://www.busit.com/ <https://www.busit.com/>
>
--
*Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
T. +33 (0)4 89 97 36 50
P. +33 (0)6 08 33 32 61
emmanuel.lecharny@busit.com https://www.busit.com/
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
For additional commands, e-mail: users-help@mina.apache.org
Re: New deadlock potential in MINA 2.2's SSLHandler
Posted by Guus der Kinderen <gu...@gmail.com>.
Hi Emmanuel,
I'm not sure if I understand what you're saying or asking. My email client
doesn't do a great job of formatting all that code in the email either,
which might add to the confusion.
The code that you seem to refer to is here:
https://github.com/igniterealtime/Openfire/blob/cd28f39c411a0faede6d04454caf865d1695928f/xmppserver/src/main/java/org/jivesoftware/openfire/session/LocalClientSession.java#L923-L932
There is a lock that intends to ensure that the 'streammanager' (which
keeps statistics on data sent, received and acknowledged) is not used while
data is being sent over the outbound connection.
Does that make sense and answer your question?
Kind regards,
Guus
On Mon, Dec 19, 2022 at 4:00 AM Emmanuel Lécharny <el...@gmail.com>
wrote:
> Hi Guus,
>
> thanks for teh full stack trace.
>
> I've some concern about this blocked thread:
> "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> java.lang.Thread.State: BLOCKED
> - blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> (owned by
> socket_c2s_ssl-thread-2 id=78)
> at
> org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> at
> org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
>
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
>
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> at
> org.jivesoftware.openfire.net
> .StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
>
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
>
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> at
>
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> at
>
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> at
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> at
>
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> - locked
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> at
>
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> at
>
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> at
>
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> ...
>
>
> As you can see, there is a lock on a StreamManager instance following a
> call to org.jivesoftware.openfire.session.La ocalSession.process:
>
> public void process(Packet packet) {
> // Check that the requested packet can be processed
> if (canProcess(packet)) {
> // Perform the actual processing of the packet. This
> usually implies sending
> // the packet to the entity
> try {
> // Invoke the interceptors before we send the packet
>
> InterceptorManager.getInstance().invokeInterceptors(packet, this, false,
> false);
> deliver(packet);
> <<<-------------------------------------Here
>
> but I don't see why a lock is taken, unless I don't have the proper
> source code.
>
> Which version are you using when having this deadlock?
>
>
> On 14/12/2022 09:37, Guus der Kinderen wrote:
> > Hi Emmanuel,
> >
> > I was trying to be helpful by leaving out unimportant details, but I
> > seem to have messed up. A third thread is involved. I've now attached
> > the full thread dump to this email.
> >
> > Kind regards,
> >
> > Guus
> >
> >
> > On Mon, Dec 12, 2022 at 9:53 AM Emmanuel Lécharny <elecharny@gmail.com
> > <ma...@gmail.com>> wrote:
> >
> > Hi Guus,
> >
> > there is something missing in the stacck trace: the two threads are
> > blocked on different monitors:
> > * SSLHandlerG0@99f49e2 owned by socket_c2s_ssl-thread-2
> > * StreamManager@7e024771 owned by TaskEngine-pool-3
> >
> > they are not related, they are not blocking each one other.
> >
> > Can you provide the full stack trace ?
> >
> > Thanks !
> >
> >
> > On 09/12/2022 10:02, Guus der Kinderen wrote:
> > > Hello,
> > >
> > > I wonder if MINA 2.2.1 introduces a new potential for deadlock in
> its
> > > SSLHandler implementation. Did something change there, as
> > compared to MINA
> > > 2.1.3?
> > >
> > > Since this upgrade, we consistently run into a thread deadlock.
> > One of the
> > > threads that is deadlocking is sending data to the peer, while
> > the other is
> > > processing data from the peer. The deadlock involves a MINA-based
> > lock (in
> > > SSLHandler), and a lock in our code (StreamManager), that is
> > responsible
> > > for recording what packets that are exchanged have been
> > acknowledged by the
> > > peer. The latter did not change, so I'm suspecting a change in
> > SSLHandler.
> > >
> > > The stack traces of two deadlocked threads are added to this
> email.
> > >
> > > Kind regards,
> > >
> > > Guus
> > >
> > >
> > > "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> > > java.lang.Thread.State: BLOCKED
> > > - blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > (owned by
> > > socket_c2s_ssl-thread-2 id=78)
> > > at
> > org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> > > at
> > org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > > at
> > >
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > > at
> > > org.jivesoftware.openfire.net
> > <http://org.jivesoftware.openfire.net
> >.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> > > at
> > >
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> > > at
> > >
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> > > at
> > >
> >
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> > > at
> > >
> >
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> > > - locked
> > org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > > at
> > >
> >
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> > > at
> > >
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> > > at
> > >
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> > > at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
> > > at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
> > > at
> > >
> >
> org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
> > > at
> > >
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
> > > at
> > >
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
> > > at java.base@11.0.17
> > >
> >
> /java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> > > at java.base@11.0.17
> > > /java.util.concurrent.FutureTask.run(FutureTask.java:264)
> > > at java.base@11.0.17
> > >
> >
> /java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> > > at java.base@11.0.17
> > >
> >
> /java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> > > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> > >
> > > "socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
> > > java.lang.Thread.State: BLOCKED
> > > - blocked on
> > > org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > (owned by
> > > TaskEngine-pool-3 id=40)
> > > at
> > >
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
> > > at
> > >
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
> > > at
> > > org.jivesoftware.openfire.net
> > <http://org.jivesoftware.openfire.net
> >.StanzaHandler.process(StanzaHandler.java:223)
> > > at
> > >
> >
> org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
> > > at
> > >
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
> > > at
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
> > > - locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > > at
> > >
> >
> org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > > at
> > >
> >
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
> > > at org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
> > > at
> > >
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
> > > at
> > >
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
> > > at
> > >
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
> > > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> > >
> >
> > --
> > *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> > T. +33 (0)4 89 97 36 50
> > P. +33 (0)6 08 33 32 61
> > emmanuel.lecharny@busit.com <ma...@busit.com>
> > https://www.busit.com/ <https://www.busit.com/>
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
> > <ma...@mina.apache.org>
> > For additional commands, e-mail: users-help@mina.apache.org
> > <ma...@mina.apache.org>
> >
>
> --
> *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> T. +33 (0)4 89 97 36 50
> P. +33 (0)6 08 33 32 61
> emmanuel.lecharny@busit.com https://www.busit.com/
>
Re: New deadlock potential in MINA 2.2's SSLHandler
Posted by Emmanuel Lécharny <el...@gmail.com>.
Hi Guus,
thanks for teh full stack trace.
I've some concern about this blocked thread:
"TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
java.lang.Thread.State: BLOCKED
- blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2 (owned by
socket_c2s_ssl-thread-2 id=78)
at org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
at org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
at
org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
at
org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
at
org.jivesoftware.openfire.net.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
at
org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
at
org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
at
org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
at
org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
at
org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
- locked org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
at
org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
at
org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
at
org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
...
As you can see, there is a lock on a StreamManager instance following a
call to org.jivesoftware.openfire.session.La ocalSession.process:
public void process(Packet packet) {
// Check that the requested packet can be processed
if (canProcess(packet)) {
// Perform the actual processing of the packet. This
usually implies sending
// the packet to the entity
try {
// Invoke the interceptors before we send the packet
InterceptorManager.getInstance().invokeInterceptors(packet, this, false,
false);
deliver(packet);
<<<-------------------------------------Here
but I don't see why a lock is taken, unless I don't have the proper
source code.
Which version are you using when having this deadlock?
On 14/12/2022 09:37, Guus der Kinderen wrote:
> Hi Emmanuel,
>
> I was trying to be helpful by leaving out unimportant details, but I
> seem to have messed up. A third thread is involved. I've now attached
> the full thread dump to this email.
>
> Kind regards,
>
> Guus
>
>
> On Mon, Dec 12, 2022 at 9:53 AM Emmanuel Lécharny <elecharny@gmail.com
> <ma...@gmail.com>> wrote:
>
> Hi Guus,
>
> there is something missing in the stacck trace: the two threads are
> blocked on different monitors:
> * SSLHandlerG0@99f49e2 owned by socket_c2s_ssl-thread-2
> * StreamManager@7e024771 owned by TaskEngine-pool-3
>
> they are not related, they are not blocking each one other.
>
> Can you provide the full stack trace ?
>
> Thanks !
>
>
> On 09/12/2022 10:02, Guus der Kinderen wrote:
> > Hello,
> >
> > I wonder if MINA 2.2.1 introduces a new potential for deadlock in its
> > SSLHandler implementation. Did something change there, as
> compared to MINA
> > 2.1.3?
> >
> > Since this upgrade, we consistently run into a thread deadlock.
> One of the
> > threads that is deadlocking is sending data to the peer, while
> the other is
> > processing data from the peer. The deadlock involves a MINA-based
> lock (in
> > SSLHandler), and a lock in our code (StreamManager), that is
> responsible
> > for recording what packets that are exchanged have been
> acknowledged by the
> > peer. The latter did not change, so I'm suspecting a change in
> SSLHandler.
> >
> > The stack traces of two deadlocked threads are added to this email.
> >
> > Kind regards,
> >
> > Guus
> >
> >
> > "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> > java.lang.Thread.State: BLOCKED
> > - blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> (owned by
> > socket_c2s_ssl-thread-2 id=78)
> > at
> org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> > at
> org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > at
> > org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> > at
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> > at
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> > at
> >
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> > at
> >
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> > - locked
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > at
> >
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> > at
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> > at
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> > at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
> > at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
> > at
> >
> org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
> > at
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
> > at
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
> > at java.base@11.0.17
> >
> /java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> > at java.base@11.0.17
> > /java.util.concurrent.FutureTask.run(FutureTask.java:264)
> > at java.base@11.0.17
> >
> /java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> > at java.base@11.0.17
> >
> /java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> >
> > "socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
> > java.lang.Thread.State: BLOCKED
> > - blocked on
> > org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> (owned by
> > TaskEngine-pool-3 id=40)
> > at
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
> > at
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
> > at
> > org.jivesoftware.openfire.net
> <http://org.jivesoftware.openfire.net>.StanzaHandler.process(StanzaHandler.java:223)
> > at
> >
> org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
> > at
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
> > at
> org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
> > - locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > at
> >
> org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
> > at org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
> > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> >
>
> --
> *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> T. +33 (0)4 89 97 36 50
> P. +33 (0)6 08 33 32 61
> emmanuel.lecharny@busit.com <ma...@busit.com>
> https://www.busit.com/ <https://www.busit.com/>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
> <ma...@mina.apache.org>
> For additional commands, e-mail: users-help@mina.apache.org
> <ma...@mina.apache.org>
>
--
*Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
T. +33 (0)4 89 97 36 50
P. +33 (0)6 08 33 32 61
emmanuel.lecharny@busit.com https://www.busit.com/
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
For additional commands, e-mail: users-help@mina.apache.org
Re: New deadlock potential in MINA 2.2's SSLHandler
Posted by Guus der Kinderen <gu...@gmail.com>.
Hi Emmanuel,
I was trying to be helpful by leaving out unimportant details, but I seem
to have messed up. A third thread is involved. I've now attached the full
thread dump to this email.
Kind regards,
Guus
On Mon, Dec 12, 2022 at 9:53 AM Emmanuel Lécharny <el...@gmail.com>
wrote:
> Hi Guus,
>
> there is something missing in the stacck trace: the two threads are
> blocked on different monitors:
> * SSLHandlerG0@99f49e2 owned by socket_c2s_ssl-thread-2
> * StreamManager@7e024771 owned by TaskEngine-pool-3
>
> they are not related, they are not blocking each one other.
>
> Can you provide the full stack trace ?
>
> Thanks !
>
>
> On 09/12/2022 10:02, Guus der Kinderen wrote:
> > Hello,
> >
> > I wonder if MINA 2.2.1 introduces a new potential for deadlock in its
> > SSLHandler implementation. Did something change there, as compared to
> MINA
> > 2.1.3?
> >
> > Since this upgrade, we consistently run into a thread deadlock. One of
> the
> > threads that is deadlocking is sending data to the peer, while the other
> is
> > processing data from the peer. The deadlock involves a MINA-based lock
> (in
> > SSLHandler), and a lock in our code (StreamManager), that is responsible
> > for recording what packets that are exchanged have been acknowledged by
> the
> > peer. The latter did not change, so I'm suspecting a change in
> SSLHandler.
> >
> > The stack traces of two deadlocked threads are added to this email.
> >
> > Kind regards,
> >
> > Guus
> >
> >
> > "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> > java.lang.Thread.State: BLOCKED
> > - blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2 (owned
> by
> > socket_c2s_ssl-thread-2 id=78)
> > at
> org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> > at
> org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > at
> > org.jivesoftware.openfire.net
> .StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> > at
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> > at
> >
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> > at
> >
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> > at
> >
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> > - locked
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> > at
> >
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> > at
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> > at
> >
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> > at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
> > at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
> > at
> >
> org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
> > at
> >
> org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
> > at
> > org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
> > at java.base@11.0.17
> > /java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> > at java.base@11.0.17
> > /java.util.concurrent.FutureTask.run(FutureTask.java:264)
> > at java.base@11.0.17
> >
> /java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> > at java.base@11.0.17
> >
> /java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> >
> > "socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
> > java.lang.Thread.State: BLOCKED
> > - blocked on
> > org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> (owned by
> > TaskEngine-pool-3 id=40)
> > at
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
> > at
> >
> org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
> > at
> > org.jivesoftware.openfire.net
> .StanzaHandler.process(StanzaHandler.java:223)
> > at
> >
> org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
> > at
> >
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
> > at
> org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
> > - locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> > at
> > org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> > at
> >
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> > at
> >
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
> > at org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
> > at
> >
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
> > at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
> >
>
> --
> *Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
> T. +33 (0)4 89 97 36 50
> P. +33 (0)6 08 33 32 61
> emmanuel.lecharny@busit.com https://www.busit.com/
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
> For additional commands, e-mail: users-help@mina.apache.org
>
>
Re: New deadlock potential in MINA 2.2's SSLHandler
Posted by Emmanuel Lécharny <el...@gmail.com>.
Hi Guus,
there is something missing in the stacck trace: the two threads are
blocked on different monitors:
* SSLHandlerG0@99f49e2 owned by socket_c2s_ssl-thread-2
* StreamManager@7e024771 owned by TaskEngine-pool-3
they are not related, they are not blocking each one other.
Can you provide the full stack trace ?
Thanks !
On 09/12/2022 10:02, Guus der Kinderen wrote:
> Hello,
>
> I wonder if MINA 2.2.1 introduces a new potential for deadlock in its
> SSLHandler implementation. Did something change there, as compared to MINA
> 2.1.3?
>
> Since this upgrade, we consistently run into a thread deadlock. One of the
> threads that is deadlocking is sending data to the peer, while the other is
> processing data from the peer. The deadlock involves a MINA-based lock (in
> SSLHandler), and a lock in our code (StreamManager), that is responsible
> for recording what packets that are exchanged have been acknowledged by the
> peer. The latter did not change, so I'm suspecting a change in SSLHandler.
>
> The stack traces of two deadlocked threads are added to this email.
>
> Kind regards,
>
> Guus
>
>
> "TaskEngine-pool-3" #40 daemon prio=5 waiting on lock
> java.lang.Thread.State: BLOCKED
> - blocked on org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2 (owned by
> socket_c2s_ssl-thread-2 id=78)
> at org.apache.mina.filter.ssl.SSLHandlerG0.write(SSLHandlerG0.java:312)
> at org.apache.mina.filter.ssl.SslFilter.filterWrite(SslFilter.java:380)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
> org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:301)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> at
> org.jivesoftware.openfire.net.StalledSessionsFilter.filterWrite(StalledSessionsFilter.java:61)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:1146)
> at
> org.apache.mina.core.filterchain.IoFilterAdapter.filterWrite(IoFilterAdapter.java:138)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:753)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:746)
> at
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:575)
> at
> org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:520)
> at
> org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:349)
> at
> org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:928)
> - locked org.jivesoftware.openfire.streammanagement.StreamManager@7e024771
> at
> org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:407)
> at
> org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableImpl.java:439)
> at
> org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:350)
> at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:426)
> at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:106)
> at
> org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:74)
> at
> org.jivesoftware.openfire.pubsub.PubSubEngine.publishItemsToNode(PubSubEngine.java:428)
> at
> org.jivesoftware.openfire.pubsub.PubSubEngine$1.run(PubSubEngine.java:96)
> at java.base@11.0.17
> /java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> at java.base@11.0.17
> /java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at java.base@11.0.17
> /java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at java.base@11.0.17
> /java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
>
> "socket_c2s_ssl-thread-2" #78 daemon prio=5 waiting on lock
> java.lang.Thread.State: BLOCKED
> - blocked on
> org.jivesoftware.openfire.streammanagement.StreamManager@7e024771 (owned by
> TaskEngine-pool-3 id=40)
> at
> org.jivesoftware.openfire.streammanagement.StreamManager.processClientAcknowledgement(StreamManager.java:493)
> at
> org.jivesoftware.openfire.streammanagement.StreamManager.process(StreamManager.java:185)
> at
> org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:223)
> at
> org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:178)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:1015)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> at
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> at
> org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.flush(AbstractProtocolDecoderOutput.java:64)
> at
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:249)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> at
> org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:236)
> at org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
> - locked org.apache.mina.filter.ssl.SSLHandlerG0@99f49e2
> at
> org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
> at
> org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:106)
> at org.apache.mina.core.session.IoEvent.run(IoEvent.java:89)
> at
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:763)
> at
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:755)
> at
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:695)
> at java.base@11.0.17/java.lang.Thread.run(Thread.java:829)
>
--
*Emmanuel Lécharny - CTO* 205 Promenade des Anglais – 06200 NICE
T. +33 (0)4 89 97 36 50
P. +33 (0)6 08 33 32 61
emmanuel.lecharny@busit.com https://www.busit.com/
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@mina.apache.org
For additional commands, e-mail: users-help@mina.apache.org