[JBoss JIRA] (JBREM-1308) MicroSocketClientInvoker hangs on SocketInputStream.read causing deadlock in MessageSucker.setConsuming
by Giovanni Pelosi (JIRA)
Giovanni Pelosi created JBREM-1308:
--------------------------------------
Summary: MicroSocketClientInvoker hangs on SocketInputStream.read causing deadlock in MessageSucker.setConsuming
Key: JBREM-1308
URL: https://issues.jboss.org/browse/JBREM-1308
Project: JBoss Remoting
Issue Type: Bug
Security Level: Public (Everyone can see)
Components: transport
Affects Versions: 2.2.4
Environment: jboss-4.2.3.GA with jboss-messaging-1.4.5.GA and latest jboss-remoting-2_2_4,
3 node cluster, jms clustered queues
Reporter: Giovanni Pelosi
In production enviroment, our jboss line of 3 clustered servers randomly (once a week) seemes to hang, refusing to reply to remote jms clients.
Taking stack trace of all jboss instances (jstack) we always see the same pattern of deadlock:
A non-pooled thread, started internally by remoting, is trying to recover a "connectionExeption" condition
(ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:120)),
but the task hangs (without timeout) on a socket read:
(MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:1077))
This non-terminating network operation holds a lock, acquired in
MessageSucker.suspend(MessageSucker.java:225)
that in turns cause deadlock in messaging layer:
org.jboss.messaging.core.impl.MessagingQueue.informSuckers(MessagingQueue.java:566)
causing blocks in all jms traffic.
Offending thread stack:
-------------------------------------------------
"Thread-5163" daemon prio=10 tid=0x00007f1bc4d10800 nid=0x2b70 runnable [0x00007f1af61e0000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:146)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
- locked <0x00000006d23445f8> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:83)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:1077)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:682)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:458)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:141)
at org.jboss.remoting.Client.invoke(Client.java:1925)
at org.jboss.remoting.Client.invoke(Client.java:786)
at org.jboss.remoting.Client.invoke(Client.java:774)
at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
at org.jboss.jms.client.delegate.ClientConsumerDelegate.org$jboss$jms$client$delegate$ClientConsumerDelegate$close$aop(ClientConsumerDelegate.java:122)
at org.jboss.jms.client.delegate.ClientConsumerDelegate$close_N4742752445160157748.invokeNext(ClientConsumerDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
at org.jboss.jms.client.delegate.ClientConsumerDelegate$close_N4742752445160157748.invokeNext(ClientConsumerDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
at org.jboss.jms.client.delegate.ClientConsumerDelegate$close_N4742752445160157748.invokeNext(ClientConsumerDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.delegate.ClientConsumerDelegate.close(ClientConsumerDelegate.java)
at org.jboss.messaging.core.impl.clusterconnection.MessageSucker.suspend(MessageSucker.java:225)
- locked <0x0000000605960788> (a org.jboss.messaging.core.impl.clusterconnection.MessageSucker)
at org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager$ConnectionInfo.cleanupConnection(ClusterConnectionManager.java:804)
- locked <0x0000000605960ca8> (a org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager$ConnectionInfo)
at org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager$ConnectionInfo.onException(ClusterConnectionManager.java:785)
at org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:120)
at org.jboss.remoting.ConnectionValidator$1.run(ConnectionValidator.java:498)
-------------------------------------------------
JMS Layer main lock
-------------------------------------------------
"Thread-5167" daemon prio=10 tid=0x00007f1be0069800 nid=0x2b82 waiting for monitor entry [0x00007f1afac2b000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.messaging.core.impl.clusterconnection.MessageSucker.setConsuming(MessageSucker.java:288)
- waiting to lock <0x0000000605960788> (a org.jboss.messaging.core.impl.clusterconnection.MessageSucker)
at org.jboss.messaging.core.impl.MessagingQueue.informSuckers(MessagingQueue.java:566)
at org.jboss.messaging.core.impl.MessagingQueue.deliverInternal(MessagingQueue.java:516)
at org.jboss.messaging.core.impl.ChannelSupport.deliver(ChannelSupport.java:375)
- locked <0x00000006012cdd50> (a java.lang.Object)
at org.jboss.jms.server.endpoint.ServerSessionEndpoint$2.run(ServerSessionEndpoint.java:1574)
at org.jboss.messaging.util.OrderedExecutorFactory$ChildExecutor.run(OrderedExecutorFactory.java:120)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
-------------------------------------------------
Sample of deadlocked JMS Client Thread:
-------------------------------------------
"WorkManager(2)-42959" daemon prio=10 tid=0x00007f1bb806c000 nid=0x2b6c waiting for monitor entry [0x00007f1adf230000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.messaging.core.impl.ChannelSupport.handle(ChannelSupport.java:242)
- waiting to lock <0x00000006012cdd50> (a java.lang.Object)
at org.jboss.messaging.core.impl.postoffice.MessagingPostOffice.routeInternal(MessagingPostOffice.java:2345)
at org.jboss.messaging.core.impl.postoffice.MessagingPostOffice.route(MessagingPostOffice.java:515)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendMessage(ServerConnectionEndpoint.java:769)
at org.jboss.jms.server.endpoint.ServerSessionEndpoint.send(ServerSessionEndpoint.java:399)
at org.jboss.jms.server.endpoint.advised.SessionAdvised.org$jboss$jms$server$endpoint$advised$SessionAdvised$send$aop(SessionAdvised.java:87)
at org.jboss.jms.server.endpoint.advised.SessionAdvised$send_7280680627620114891.invokeNext(SessionAdvised$send_7280680627620114891.java)
at org.jboss.jms.server.container.SecurityAspect.handleSend(SecurityAspect.java:157)
at sun.reflect.GeneratedMethodAccessor153.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
at org.jboss.jms.server.endpoint.advised.SessionAdvised$send_7280680627620114891.invokeNext(SessionAdvised$send_7280680627620114891.java)
at org.jboss.jms.server.endpoint.advised.SessionAdvised.send(SessionAdvised.java)
at org.jboss.jms.wireformat.SessionSendRequest.serverInvoke(SessionSendRequest.java:95)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:157)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:862)
at org.jboss.remoting.ServerInvoker$1.run(ServerInvoker.java:1901)
at org.jboss.jms.server.remoting.DirectThreadPool.run(DirectThreadPool.java:63)
at org.jboss.remoting.ServerInvoker.handleOnewayInvocation(ServerInvoker.java:1912)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:832)
at org.jboss.remoting.transport.local.LocalClientInvoker.invoke(LocalClientInvoker.java:101)
at org.jboss.remoting.Client.invoke(Client.java:1925)
at org.jboss.remoting.Client.invoke(Client.java:786)
at org.jboss.remoting.Client.invokeOneway(Client.java:837)
at org.jboss.remoting.Client.invokeOneway(Client.java:1023)
at org.jboss.remoting.Client.invokeOneway(Client.java:1014)
at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:180)
at org.jboss.jms.client.delegate.DelegateSupport.doInvokeOneway(DelegateSupport.java:165)
at org.jboss.jms.client.delegate.ClientSessionDelegate.org$jboss$jms$client$delegate$ClientSessionDelegate$send$aop(ClientSessionDelegate.java:495)
at org.jboss.jms.client.delegate.ClientSessionDelegate$send_6145266547759487588.invokeNext(ClientSessionDelegate$send_6145266547759487588.java)
at org.jboss.jms.client.container.SessionAspect.handleSend(SessionAspect.java:661)
at org.jboss.aop.advice.org.jboss.jms.client.container.SessionAspect28.invoke(SessionAspect28.java)
at org.jboss.jms.client.delegate.ClientSessionDelegate$send_6145266547759487588.invokeNext(ClientSessionDelegate$send_6145266547759487588.java)
at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
at org.jboss.jms.client.delegate.ClientSessionDelegate$send_6145266547759487588.invokeNext(ClientSessionDelegate$send_6145266547759487588.java)
at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
at org.jboss.jms.client.delegate.ClientSessionDelegate$send_6145266547759487588.invokeNext(ClientSessionDelegate$send_6145266547759487588.java)
at org.jboss.jms.client.delegate.ClientSessionDelegate.send(ClientSessionDelegate.java)
at org.jboss.jms.client.container.ProducerAspect.handleSend(ProducerAspect.java:276)
at org.jboss.aop.advice.org.jboss.jms.client.container.ProducerAspect39.invoke(ProducerAspect39.java)
at org.jboss.jms.client.delegate.ClientProducerDelegate$send_3961598017717988886.invokeNext(ClientProducerDelegate$send_3961598017717988886.java)
at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
at org.jboss.jms.client.delegate.ClientProducerDelegate$send_3961598017717988886.invokeNext(ClientProducerDelegate$send_3961598017717988886.java)
at org.jboss.jms.client.delegate.ClientProducerDelegate.send(ClientProducerDelegate.java)
at org.jboss.jms.client.JBossMessageProducer.send(JBossMessageProducer.java:165)
at org.jboss.jms.client.JBossMessageProducer.send(JBossMessageProducer.java:208)
at org.jboss.jms.client.JBossMessageProducer.send(JBossMessageProducer.java:146)
at com.pirelli.pmp.jms.JmsClient.send(JmsClient.java:457)
at com.pirelli.pmp.jms.JmsClient.send(JmsClient.java:606)
at com.pirelli.pmp.jms.JmsClient.send(JmsClient.java:655)
at com.pirelli.pmp.jms.GuiResponseQueueHelper.sendReplyMessage(GuiResponseQueueHelper.java:31)
at com.pirelli.pmp.jms.GuiResponseQueueHelper.sendReplyMessage(GuiResponseQueueHelper.java:26)
at com.pirelli.pmp.mdb.ActivityStarterMdb.replyToGUI(ActivityStarterMdb.java:153)
at com.pirelli.pmp.mdb.ActivityStarterMdb.onMessage(ActivityStarterMdb.java:95)
at sun.reflect.GeneratedMethodAccessor1335.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:249)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:268)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
at $Proxy117.onMessage(Unknown Source)
at org.jboss.resource.adapter.jms.inflow.JmsServerSession.onMessage(JmsServerSession.java:178)
at org.jboss.jms.client.container.ClientConsumer.callOnMessageStatic(ClientConsumer.java:160)
at org.jboss.jms.client.container.SessionAspect.handleRun(SessionAspect.java:831)
at org.jboss.aop.advice.org.jboss.jms.client.container.SessionAspect14.invoke(SessionAspect14.java)
at org.jboss.jms.client.delegate.ClientSessionDelegate$run_N8003352271541955702.invokeNext(ClientSessionDelegate$run_N8003352271541955702.java)
at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
at org.jboss.jms.client.delegate.ClientSessionDelegate$run_N8003352271541955702.invokeNext(ClientSessionDelegate$run_N8003352271541955702.java)
at org.jboss.jms.client.delegate.ClientSessionDelegate.run(ClientSessionDelegate.java)
at org.jboss.jms.client.JBossSession.run(JBossSession.java:199)
at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:237)
at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)
at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761)
at java.lang.Thread.run(Thread.java:679)
-------------------------------------------
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira