Remoting Deadlock in WildFly 9.0.2.Final?
jfisherdev Aug 28, 2017 5:52 PMWe recently upgraded our enterprise suite from running on JBoss AS 4.2.2 to WildFly 9.0.2.Final and since putting it in production we have been encountering a deadlock in some cases. I suspect the issue could be somewhere in an application, as it seems to happen primarily when a particular is deployed to the server, but unfortunately there has been nothing to point back to that from what information has been captured. Most of the time when this has been reported, it's when a remote standalone EJB client application is trying to connect to the server via EJB client invocation and is receiving no response. I am unfortunately only aware of this issue after the fact, as it's reported by customer support staff and to this point has been resolved by restarting the WildFly server. We have been able to capture thread dumps prior to restarting and have observed a pattern of deadlocking that looks like this:
The thread, which is usually an "EJB default - ..." thread, calling org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener.send() is waiting for a lock owned by another thread, which is usually a "default I/O - ..." thread, calling
org.jboss.remoting3.remote.OutboundMessage.cancel(). Thread dump information is provided at the end of the post.
Looking through the JBoss Remoting project issue tracker it looks like this issue was reported and addressed in 4.0.7 [REM3-204] Deadlock when connection is closing while we are writing - JBoss Issue Tracker but was reported in version 4.0.8 and later marked as cannot reproduce [REM3-226] Deadlock when connection is closing while we are writing - JBoss Issue Tracker. It sounds like it should be fixed in version 4.0.9, which is bundled with WildFly, but that doesn't seem to be the case.
This is a frustrating issue on many fronts as we have not been able to reproduce it internally or in testing and it only first appeared in production, we have not found anything that points to an issue on the application side, and, worst of all, it has unfortunately created a negative end user experience and consequently some resistance to upgrading to WildFly 9.
We need to do something about this, but we don't know what that is.
The main questions we have are:
- First and foremost, is this a library issue or something else?
- If it is a library issue, do we need to upgrade something, whether that's the Remoting library or WildFly itself?
- If this is something application related, what should we look for on the application side that might be causing the deadlock?
- Is there anything on the configuration side that could cause this?
Any information that could help would be very much appreciated.
Note that the thread dumps are captured via Jolokia, hence the JSON formatting, and that this is on a standalone server.
{
"thread-id" => 1381L,
"thread-name" => "EJB default - 220",
"thread-state" => "BLOCKED",
"blocked-time" => -1L,
"blocked-count" => 2L,
"waited-time" => -1L,
"waited-count" => 504L,
"lock-info" => {
"class-name" => "java.util.ArrayDeque",
"identity-hash-code" => 355091095
},
"lock-name" => "java.util.ArrayDeque@152a4297",
"lock-owner-id" => 159L,
"lock-owner-name" => "default I/O-14",
"stack-trace" => [
{
"file-name" => "RemoteConnection.java",
"line-number" => 300,
"class-name" => "org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener",
"method-name" => "send",
"native-method" => false
},
{
"file-name" => "RemoteConnection.java",
"line-number" => 123,
"class-name" => "org.jboss.remoting3.remote.RemoteConnection",
"method-name" => "send",
"native-method" => false
},
{
"file-name" => "OutboundMessage.java",
"line-number" => 154,
"class-name" => "org.jboss.remoting3.remote.OutboundMessage$1",
"method-name" => "accept",
"native-method" => false
},
{
"file-name" => "BufferPipeOutputStream.java",
"line-number" => 122,
"class-name" => "org.xnio.streams.BufferPipeOutputStream",
"method-name" => "send",
"native-method" => false
},
{
"file-name" => "BufferPipeOutputStream.java",
"line-number" => 110,
"class-name" => "org.xnio.streams.BufferPipeOutputStream",
"method-name" => "send",
"native-method" => false
},
{
"file-name" => "BufferPipeOutputStream.java",
"line-number" => 139,
"class-name" => "org.xnio.streams.BufferPipeOutputStream",
"method-name" => "flush",
"native-method" => false
},
{
"file-name" => "BufferPipeOutputStream.java",
"line-number" => 131,
"class-name" => "org.xnio.streams.BufferPipeOutputStream",
"method-name" => "flush",
"native-method" => false
},
{
"file-name" => "OutboundMessage.java",
"line-number" => 277,
"class-name" => "org.jboss.remoting3.remote.OutboundMessage",
"method-name" => "flush",
"native-method" => false
},
{
"file-name" => "DataOutputStream.java",
"line-number" => 123,
"class-name" => "java.io.DataOutputStream",
"method-name" => "flush",
"native-method" => false
},
{
"file-name" => "FilterOutputStream.java",
"line-number" => 158,
"class-name" => "java.io.FilterOutputStream",
"method-name" => "close",
"native-method" => false
},
{
"file-name" => "IoUtils.java",
"line-number" => 134,
"class-name" => "org.xnio.IoUtils",
"method-name" => "safeClose",
"native-method" => false
},
{
"file-name" => "MethodInvocationMessageHandler.java",
"line-number" => 380,
"class-name" => "org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler",
"method-name" => "writeMethodInvocationResponse",
"native-method" => false
},
{
"file-name" => "MethodInvocationMessageHandler.java",
"line-number" => 69,
"class-name" => "org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler",
"method-name" => "access$600",
"native-method" => false
},
{
"file-name" => "MethodInvocationMessageHandler.java",
"line-number" => 245,
"class-name" => "org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1",
"method-name" => "run",
"native-method" => false
},
{
"file-name" => "Executors.java",
"line-number" => 511,
"class-name" => "java.util.concurrent.Executors$RunnableAdapter",
"method-name" => "call",
"native-method" => false
},
{
"file-name" => "FutureTask.java",
"line-number" => 266,
"class-name" => "java.util.concurrent.FutureTask",
"method-name" => "run",
"native-method" => false
},
{
"file-name" => "ThreadPoolExecutor.java",
"line-number" => 1142,
"class-name" => "java.util.concurrent.ThreadPoolExecutor",
"method-name" => "runWorker",
"native-method" => false
},
{
"file-name" => "ThreadPoolExecutor.java",
"line-number" => 617,
"class-name" => "java.util.concurrent.ThreadPoolExecutor$Worker",
"method-name" => "run",
"native-method" => false
},
{
"file-name" => "Thread.java",
"line-number" => 745,
"class-name" => "java.lang.Thread",
"method-name" => "run",
"native-method" => false
},
{
"file-name" => "JBossThread.java",
"line-number" => 320,
"class-name" => "org.jboss.threads.JBossThread",
"method-name" => "run",
"native-method" => false
}
],
"suspended" => false,
"in-native" => false,
"locked-monitors" => [],
"locked-synchronizers" => []
}
{
"thread-id" => 159L,
"thread-name" => "default I/O-14",
"thread-state" => "BLOCKED",
"blocked-time" => -1L,
"blocked-count" => 13L,
"waited-time" => -1L,
"waited-count" => 3L,
"lock-info" => {
"class-name" => "org.xnio.streams.BufferPipeOutputStream",
"identity-hash-code" => 1575379229
},
"lock-name" => "org.xnio.streams.BufferPipeOutputStream@5de6611d",
"lock-owner-id" => 1381L,
"lock-owner-name" => "EJB default - 220",
"stack-trace" => [
{
"file-name" => "OutboundMessage.java",
"line-number" => 289,
"class-name" => "org.jboss.remoting3.remote.OutboundMessage",
"method-name" => "cancel",
"native-method" => false
},
{
"file-name" => "RemoteConnectionChannel.java",
"line-number" => 560,
"class-name" => "org.jboss.remoting3.remote.RemoteConnectionChannel",
"method-name" => "closeMessages",
"native-method" => false
},
{
"file-name" => "RemoteConnectionChannel.java",
"line-number" => 542,
"class-name" => "org.jboss.remoting3.remote.RemoteConnectionChannel",
"method-name" => "closeAction",
"native-method" => false
},
{
"file-name" => "AbstractHandleableCloseable.java",
"line-number" => 372,
"class-name" => "org.jboss.remoting3.spi.AbstractHandleableCloseable",
"method-name" => "closeAsync",
"native-method" => false
},
{
"file-name" => "RemoteConnectionHandler.java",
"line-number" => 429,
"class-name" => "org.jboss.remoting3.remote.RemoteConnectionHandler",
"method-name" => "closeAllChannels",
"native-method" => false
},
{
"file-name" => "RemoteConnectionHandler.java",
"line-number" => 233,
"class-name" => "org.jboss.remoting3.remote.RemoteConnectionHandler",
"method-name" => "sendCloseRequest",
"native-method" => false
},
{
"file-name" => "RemoteConnectionHandler.java",
"line-number" => 113,
"class-name" => "org.jboss.remoting3.remote.RemoteConnectionHandler",
"method-name" => "handleConnectionClose",
"native-method" => false
},
{
"file-name" => "RemoteReadListener.java",
"line-number" => 82,
"class-name" => "org.jboss.remoting3.remote.RemoteReadListener",
"method-name" => "handleEvent",
"native-method" => false
},
{
"file-name" => "RemoteReadListener.java",
"line-number" => 45,
"class-name" => "org.jboss.remoting3.remote.RemoteReadListener",
"method-name" => "handleEvent",
"native-method" => false
},
{
"file-name" => "ChannelListeners.java",
"line-number" => 92,
"class-name" => "org.xnio.ChannelListeners",
"method-name" => "invokeChannelListener",
"native-method" => false
},
{
"file-name" => "TranslatingSuspendableChannel.java",
"line-number" => 199,
"class-name" => "org.xnio.channels.TranslatingSuspendableChannel",
"method-name" => "handleReadable",
"native-method" => false
},
{
"file-name" => "TranslatingSuspendableChannel.java",
"line-number" => 113,
"class-name" => "org.xnio.channels.TranslatingSuspendableChannel$1",
"method-name" => "handleEvent",
"native-method" => false
},
{
"file-name" => "ChannelListeners.java",
"line-number" => 92,
"class-name" => "org.xnio.ChannelListeners",
"method-name" => "invokeChannelListener",
"native-method" => false
},
{
"file-name" => "ChannelListeners.java",
"line-number" => 1092,
"class-name" => "org.xnio.ChannelListeners$DelegatingChannelListener",
"method-name" => "handleEvent",
"native-method" => false
},
{
"file-name" => "ChannelListeners.java",
"line-number" => 92,
"class-name" => "org.xnio.ChannelListeners",
"method-name" => "invokeChannelListener",
"native-method" => false
},
{
"file-name" => "ReadReadyHandler.java",
"line-number" => 66,
"class-name" => "org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler",
"method-name" => "readReady",
"native-method" => false
},
{
"file-name" => "NioSocketConduit.java",
"line-number" => 88,
"class-name" => "org.xnio.nio.NioSocketConduit",
"method-name" => "handleReady",
"native-method" => false
},
{
"file-name" => "WorkerThread.java",
"line-number" => 539,
"class-name" => "org.xnio.nio.WorkerThread",
"method-name" => "run",
"native-method" => false
}
],
"suspended" => false,
"in-native" => false,
"locked-monitors" => [],
"locked-synchronizers" => []
}