Uploaded image for project: 'JBoss Remoting'
  1. JBoss Remoting
  2. JBREM-1308

MicroSocketClientInvoker hangs on SocketInputStream.read causing deadlock in MessageSucker.setConsuming

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Major
    • Resolution: Rejected
    • Affects Version/s: 2.2.4, 2.5.4.SP3
    • Fix Version/s: None
    • Component/s: transport
    • Labels:
      None
    • Steps to Reproduce:
      Hide

      not easy to reproduce. The issue was verified weekly under moderate continuous (24x7) system generated traffic.

      Show
      not easy to reproduce. The issue was verified weekly under moderate continuous (24x7) system generated traffic.

      Description

      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)

      -------------------------------------------

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                ron_sigal Ronald Sigal
                Reporter:
                hute37 Giovanni Pelosi
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: