[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
Tue Jul 3 12:38:12 EDT 2012


    [ https://issues.jboss.org/browse/JBREM-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12704423#comment-12704423 ] 

Giovanni Pelosi commented on JBREM-1308:
----------------------------------------

i will try the proposed update asap.

I'va seen a lot of changes in code

org.jboss.remoting.transport.socket.MicroSocketClientInvoker#transport

betweeen 2.2.4 and 2.5.4 versions ...

In particular, i see in the 2.5.4 version this code (missing in 2.2.4) 
at line 935 of MicroSocketClientInvoker.java



            if (serverSideOneway)
            {
               if(trace) { log.trace(this + " sent oneway invocation, so not waiting for response, returning null"); }
            }
            else if (oneway)
            {
               if (performVersioning && useOnewayConnectionTimeout)
               {
                  int onewaySavedTimeout = socketWrapper.getTimeout();
                  socketWrapper.setTimeout(onewayConnectionTimeout);
                  InputStream inputStream = socketWrapper.getInputStream();
                  version = readVersion(inputStream);
                  if (version == -1)
                  {
                     throw new EOFException("end of file");
                  }
                  if (version == SocketWrapper.CLOSING)
                  {
                     log.trace(this + " received version 254: treating as end of file");
                     throw new EOFException("end of file");
                  }

                  // Note that if an exception is thrown, the socket is thrown away,
                  // so there's no need to reset the timeout value.
                  socketWrapper.setTimeout(onewaySavedTimeout);
               }
            }


I think that 2.5.4 check socket timeouts in readVersion method, that where 2.2.4 version hangs ...

I don't know if the change can be easily backported.


                
> 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
>         Attachments: jstack-20120604-0501.log, jstack-20120604-0502.log, jstack-20120604-0503.log
>
>
> 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