[jboss-remoting-issues] [JBoss JIRA] (JBREM-1308) MicroSocketClientInvoker hangs on SocketInputStream.read causing deadlock in MessageSucker.setConsuming

Giovanni Pelosi (JIRA) jira-events at lists.jboss.org
Mon Jun 4 07:25:19 EDT 2012


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

        


More information about the jboss-remoting-issues mailing list