12 Replies Latest reply on Jan 12, 2010 2:05 AM by hiten1972

    Server shutdown is blocked in ClosedInterceptor

      Hello,

       

      I use a JBoss cluster (4.2.2.GA) with two nodes and JBoss Messaging 1.4.4.GA.

       

      I have a problem with server shutdown if the other node was already restarted:

       

      1.) Start node 1

      2.) Start node 2

      3.) Stop node 1 (works fine)

      4.) Start node 1

      5.) Stop node 2 (shutdown is blocked)

       

      The shutdown hangs in the ClosedInterceptor class:


      "JBoss Shutdown Hook" daemon prio=6 tid=0x28d58c00 nid=0x26fc in Object.wait() [0x2febc000..0x2febfd14]
         java.lang.Thread.State: WAITING (on object monitor)
          at java.lang.Object.wait(Native Method)
          - waiting on <0x0c435408> (a org.jboss.jms.client.container.ClosedInterceptor)
          at java.lang.Object.wait(Object.java:485)
          at org.jboss.jms.client.container.ClosedInterceptor.checkCloseAlreadyDone(ClosedInterceptor.java:245)
          - locked <0x0c435408> (a org.jboss.jms.client.container.ClosedInterceptor)
          at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:142)
          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.jms.client.container.ClosedInterceptor.maintainRelatives(ClosedInterceptor.java:306)
          at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:165)
          at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
          at org.jboss.jms.client.delegate.ClientSessionDelegate$closing_2473194355759371067.invokeNext(ClientSessionDelegate$closing_2473194355759371067.java)
          at org.jboss.jms.client.delegate.ClientSessionDelegate.closing(ClientSessionDelegate.java)
          at org.jboss.jms.client.JBossConnectionConsumer.doClose(JBossConnectionConsumer.java:337)
          - locked <0x0c42f408> (a org.jboss.jms.client.JBossConnectionConsumer)
          at org.jboss.jms.client.JBossConnectionConsumer.close(JBossConnectionConsumer.java:163)
          at org.jboss.resource.adapter.jms.inflow.JmsServerSessionPool.teardownConsumer(JmsServerSessionPool.java:277)
          at org.jboss.resource.adapter.jms.inflow.JmsServerSessionPool.stop(JmsServerSessionPool.java:99)
          at org.jboss.resource.adapter.jms.inflow.JmsActivation.teardownSessionPool(JmsActivation.java:616)
          at org.jboss.resource.adapter.jms.inflow.JmsActivation.teardown(JmsActivation.java:335)
          at org.jboss.resource.adapter.jms.inflow.JmsActivation.stop(JmsActivation.java:226)

      remoting-bisocket:

       

        <mbean code="org.jboss.remoting.transport.Connector"
                name="jboss.messaging:service=Connector,transport=bisocket"
                display-name="Bisocket Transport Connector">
            <attribute name="Configuration">
               <config>
                  <invoker transport="bisocket">           
                     <!-- There should be no reason to change these parameters - warning! Changing them may stop JBoss Messaging working correctly -->           
                     <attribute name="marshaller" isParam="true">org.jboss.jms.wireformat.JMSWireFormat</attribute>
                     <attribute name="unmarshaller" isParam="true">org.jboss.jms.wireformat.JMSWireFormat</attribute>
                     <attribute name="dataType" isParam="true">jms</attribute>
                     <attribute name="socket.check_connection" isParam="true">false</attribute>              
                     <attribute name="serverBindAddress">${jboss.bind.address}</attribute>
                     <attribute name="serverBindPort">4457</attribute>
                     <attribute name="clientSocketClass" isParam="true">org.jboss.jms.client.remoting.ClientSocketWrapper</attribute>
                     <attribute name="serverSocketClass">org.jboss.jms.server.remoting.ServerSocketWrapper</attribute>
                
                     <attribute name="numberOfCallRetries" isParam="true">1</attribute>
                     <attribute name="pingFrequency" isParam="true">214748364</attribute>
                     <attribute name="pingWindowFactor" isParam="true">10</attribute>
                     <attribute name="onewayThreadPool">org.jboss.jms.server.remoting.DirectThreadPool</attribute>              
                     <!-- End immutable parameters -->
                    
                     <attribute name="stopLeaseOnFailure" isParam="true">false</attribute>
                    
                     <!-- Periodicity of client pings. Server window by default is twice this figure -->                              
                     <attribute name="clientLeasePeriod" isParam="true">10000</attribute>
                     <attribute name="validatorPingPeriod" isParam="true">10000</attribute>
                     <attribute name="validatorPingTimeout" isParam="true">5000</attribute>
                     <attribute name="registerCallbackListener">false</attribute>
                    
                     <attribute name="failureDisconnectTimeout" isParam="true">0</attribute>
                     <attribute name="callbackErrorsAllowed">1</attribute>
                     <attribute name="useClientConnectionIdentity" isParam="true">true</attribute>
                       
                     <!--<attribute name="timeout" isParam="true">0</attribute>       -->              
                     <attribute name="timeout" isParam="true">200000</attribute>

       

                     <!-- Number of seconds to wait for a connection in the client pool to become free -->
                     <attribute name="numberOfRetries" isParam="true">10</attribute>

       

                     <!-- Max Number of connections in client pool. This should be significantly higher than the max number of sessions/consumers you expect -->
                     <attribute name="JBM_clientMaxPoolSize" isParam="true">2000</attribute>
                    
                     <!-- The maximum time to wait before timing out on trying to write a message to socket for delivery -->
                     <attribute name="callbackTimeout">100000</attribute>
                    
                     <!-- Use these parameters to specify values for binding and connecting control connections to
                          work with your firewall/NAT configuration
                     -->
                     <attribute name="secondaryBindPort">10042</attribute>
                     <!--
                     <attribute name="secondaryConnectPort">abc</attribute>
                     -->
                               
                  </invoker>
                  <handlers>
                     <handler subsystem="JMS">org.jboss.jms.server.remoting.JMSServerInvocationHandler</handler>
                  </handlers>
               </config>
            </attribute>
         </mbean>

       

      oracle-persistence.xml:

       

      <attribute name="Clustered">true</attribute>

      <attribute name="FailoverOnNodeLeave">false</attribute>

       

       

      What can I do to get everytime a clean server shutdown?

        • 1. Re: Server shutdown is blocked in ClosedInterceptor
          gaohoward

          Can you describe what your applications on both nodes are doing when the shutdown sequence happens?

           

          Howard

          • 2. Re: Server shutdown is blocked in ClosedInterceptor

            Hello Howard,

             

            I can reproduce the problem without any jboss messaging communication running, just a few Quartz jobs are executed every minute.

             

            Debug information for shutdown node:

             

            09:23:18,152 INFO  [org.jboss.system.server.Server] Shutting down the server, blockingShutdown: false
            09:23:18,152 INFO  [org.jboss.system.server.Server] Server exit(0) called
            09:23:18,152 INFO  [org.jboss.system.server.Server] Runtime shutdown hook called, forceHalt: true
            09:23:18,152 INFO  [org.jboss.system.server.Server] JBoss SHUTDOWN: Undeploying all packages
            09:23:18,496 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
            09:23:21,152 INFO  [org.jboss.ejb3.EJBContainer] STOPPED EJB: de.impex.service.DataReceiverService ejbName: DataReceiverService
            09:24:00,138 DEBUG [org.jboss.messaging.core.impl.OrderingGroupMonitor] message doesn't have group prop, fine by me
            09:24:00,153 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[4sq6y5g-rom1km-g38ehh39-1-g38ek8xz-131+4sq6y5g-rom1km-g38ehh39-1-g38
            ek8xz-134] got PUSH callback InvocationRequest[1364a7f, ClientDelivery[JBossMessage[21220969324642305]:PERSISTENT]]
            09:24:00,153 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[4sq6y5g-rom1km-g38ehh39-1-g38ek8xz-131+4sq6y5g-rom1km-g38ehh39-1-g38
            ek8xz-134] sending ASYNCHRONOUSLY the callback to the client

            09:24:01,466 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
            09:24:01,466 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
            09:25:00,124 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] Session id for callback handler is 4sq6y5g-r430t8-g38elddr-1-g38ericd-2xe+4sq6y5g-r430t8-g38elddr
            -1-g38erid8-2xh
            09:25:00,124 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[4sq6y5g-r430t8-g38elddr-1-g38ericd-2xe+4sq6y5g-r430t8-g38elddr-1-g38
            erid8-2xh] using callbackTimeout value 100000
            09:25:00,124 DEBUG [org.jboss.remoting.callback.DefaultCallbackErrorHandler] DefaultCallbackErrorHandler[UNITIALIZED] setting server invoker to SocketServerInvoker[169.254.0.1
            06:4457]
            09:25:00,124 DEBUG [org.jboss.remoting.callback.DefaultCallbackErrorHandler] DefaultCallbackErrorHandler[SocketServerInvoker[169.254.0.106:4457]] setting callback handler to S
            erverInvokerCallbackHandler[4sq6y5g-r430t8-g38elddr-1-g38ericd-2xe+4sq6y5g-r430t8-g38elddr-1-g38erid8-2xh]
            09:25:00,124 DEBUG [org.jboss.remoting.Client] Client[21335439:4sq6y5g-rom1km-g38ehh39-1-g38erie4-4zp].connect(null)
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting maxPoolSize to 1
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting client socket wrapp
            er class name to org.jboss.jms.client.remoting.ClientSocketWrapper
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting shouldCheckConnecti
            on to false
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting timeout to 100000
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] constructed
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting maxPoolSize to 1
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting client socket wrapp
            er class name to org.jboss.jms.client.remoting.ClientSocketWrapper
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting shouldCheckConnecti
            on to false
            09:25:00,124 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] setting timeout to 100000
            09:25:00,139 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] :registered 4sq6y5g-r430t8-g
            38elddr-1-g38erid8-2xh -> SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579]
            09:25:00,139 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] Setting ping frequency to: 214748364
            09:25:00,139 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] connecting
            09:25:00,139 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] got control socket( 4sq6y5g-r430t8-g38elddr-1-g38erid8-2xh): Socket[addr=/169.254.0.106,port=1
            219,localport=10042]
            09:25:00,139 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] Creating semaphore with size 1
            09:25:00,139 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] connected
            09:25:00,139 DEBUG [org.jboss.remoting.Client] Client[21335439:4sq6y5g-rom1km-g38ehh39-1-g38erie4-4zp] connected to InvokerLocator [bisocket://172.26.250.196:309199579/callbac
            k?callbackServerHost=172.26.250.196&callbackServerPort=309199579&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSock
            etWrapper&datatype=jms&guid=4sq6y5g-r430t8-g38elddr-1-g38erict-2xg&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.
            jboss.jms.server.remoting.ServerSocketWrapper]
            09:25:00,139 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] adding callback handler ServerInvokerCallbackHandler[4sq6y5g-r430t8-g38elddr-1-g38ericd-2xe+4sq6y
            5g-r430t8-g38elddr-1-g38erid8-2xh]
            09:25:00,139 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] found calllback handler for remoting session ...-g38ericd-2xe UID=4sq6y5g-r430t8-g38elddr-1-g38er
            icd-2xe
            09:25:00,139 DEBUG [org.jboss.jms.server.connectionmanager.SimpleConnectionManager] registered connection ConnectionEndpoint[rz4-jeire83g-1-93hhe83g-mk1mor-g5y6qs4] as ...-g38
            ericd-2xe
            09:25:00,139 DEBUG [org.jboss.jms.server.security.SecurityMetadataStore] No SecurityMetadadata was available for MonitoringRecordTickBroadcastTopicMitte, using default securit
            y config
            09:25:00,139 DEBUG [org.jboss.messaging.core.impl.OrderingGroupMonitor] message doesn't have group prop, fine by me
            09:25:00,139 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[4sq6y5g-rom1km-g38ehh39-1-g38ek8xz-131+4sq6y5g-rom1km-g38ehh39-1-g38
            ek8xz-134] got PUSH callback InvocationRequest[117b4a4, ClientDelivery[JBossMessage[21220970307698690]:PERSISTENT]]
            09:25:00,139 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[4sq6y5g-rom1km-g38ehh39-1-g38ek8xz-131+4sq6y5g-rom1km-g38ehh39-1-g38
            ek8xz-134] sending ASYNCHRONOUSLY the callback to the client
            09:25:00,171 DEBUG [org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection ConnectionEndpoint[rz4-jeire83g-1-93hhe83g-mk1mor-g5y6qs4] with rem
            oting session ID ...-g38ericd-2xe
            09:25:00,171 DEBUG [org.jboss.remoting.InvokerRegistry] removed SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] from registry
            09:25:00,171 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[150db3a, bisocket://172.26.250.196:309199579] disconnecting ...
            09:25:00,171 DEBUG [org.jboss.remoting.Client] Client[21335439:4sq6y5g-rom1km-g38ehh39-1-g38erie4-4zp] is disconnected
            09:25:00,171 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] removing callback handler ServerInvokerCallbackHandler[4sq6y5g-r430t8-g38elddr-1-g38ericd-2xe+4sq
            6y5g-r430t8-g38elddr-1-g38erid8-2xh]

             

            Debug information for cluster node:

             

            09:24:00,169 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@1d0b009 from registry
            09:24:00,169 DEBUG [org.jboss.remoting.Client] Client[23861347:4sq6y5g-r430t8-g38elddr-1-g38eq82z-2x9] is disconnected
            09:24:00,169 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] removing callback handler ServerInvokerCallbackHandler[4sq6y5g-r430t8-g38elddr-1-g38eq81o-2x4+4sq
            6y5g-r430t8-g38elddr-1-g38eq82j-2x7]
            09:24:00,169 DEBUG [org.jboss.remoting.Client] Client[30756867:4sq6y5g-r430t8-g38elddr-1-g38eq81o-2x4].connect(null)
            09:24:00,169 DEBUG [org.jboss.remoting.Client] Client[30756867:4sq6y5g-r430t8-g38elddr-1-g38eq81o-2x4] connected to InvokerLocator [bisocket://172.26.250.196:860491818/callbac
            k?callbackServerHost=172.26.250.196&callbackServerPort=860491818&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSock
            etWrapper&datatype=jms&guid=4sq6y5g-r430t8-g38elddr-1-g38eq823-2x6&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.
            jboss.jms.server.remoting.ServerSocketWrapper]
            09:24:00,185 DEBUG [org.jboss.remoting.ServerInvoker] ServerInvoker (SocketServerInvoker[UNINITIALIZED]) removing client callback handler with session id of 4sq6y5g-r430t8-g38
            elddr-1-g38eq81o-2x4+4sq6y5g-r430t8-g38elddr-1-g38eq82j-2x7.
            09:24:00,185 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] unrecognized listener ID: 4sq6y5g-r430t8-g38elddr-1-g38eq82j-2x7
            09:24:00,185 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@1004566 from registry
            09:24:00,185 DEBUG [org.jboss.remoting.Client] Client[30756867:4sq6y5g-r430t8-g38elddr-1-g38eq81o-2x4] is disconnected
            09:24:00,185 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
            09:24:00,185 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@811c52's count, current count 102
            09:24:00,185 DEBUG [org.jboss.remoting.Client] Client[16420954:4sq6y5g-r430t8-g38elddr-1-g38eq81o-2x4] is disconnected
            09:24:00,185 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@1a09c82's count, current count 102
            09:24:00,185 DEBUG [org.jboss.remoting.Client] Client[18069967:4sq6y5g-r430t8-g38elddr-1-g38eq81o-2x5] is disconnected

            • 3. Re: Server shutdown is blocked in ClosedInterceptor
              gaohoward

              I'll take a look, thanks.

              • 4. Re: Server shutdown is blocked in ClosedInterceptor
                gaohoward

                Hi Alexander,

                 

                In your debug log (shutdown node):

                 

                09:25:00,139 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[4sq6y5g-rom1km-g38ehh39-1-g38ek8xz-131+4sq6y5g-rom1km-g38ehh39-1-g38
                ek8xz-134] got PUSH callback InvocationRequest[117b4a4, ClientDelivery[JBossMessage[21220970307698690]:PERSISTENT]]

                 

                That suggests that there is a message being delivered when shutdown happens.

                • 5. Re: Server shutdown is blocked in ClosedInterceptor

                  You are right, one of our jobs is sending a message to a topic every minute, I missed that.

                  Do you think that this could be the reason for my problem?

                  • 6. Re: Server shutdown is blocked in ClosedInterceptor

                    I removed the message delivery temporarily but I have still the same effect.

                     

                    Here are the new log messages:

                     

                    12:30:33,331 INFO  [org.jboss.system.server.Server] Shutting down the server, blockingShutdown: false
                    12:30:33,331 INFO  [org.jboss.system.server.Server] Server exit(0) called
                    12:30:33,331 INFO  [org.jboss.system.server.Server] Runtime shutdown hook called, forceHalt: true
                    12:30:33,347 INFO  [org.jboss.system.server.Server] JBoss SHUTDOWN: Undeploying all packages
                    12:30:34,003 INFO  [org.jboss.ejb3.EJBContainer] STOPPED EJB: de.impex.service.DataReceiverService ejbName: DataReceiverService
                    12:30:34,003 DEBUG [org.jboss.jms.server.connectionfactory.ConnectionFactoryJNDIMapper] Server[3].ConnFactoryJNDIMapper received notification from node 3
                    12:30:34,003 DEBUG [org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection ConnectionEndpoint[rf-wl7al83g-1-9xv7l83g-9wts1w-k5027p4] with remo
                    ting session ID ...-g38la5ov-6q
                    12:30:34,003 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@165ad40 from registry
                    12:30:34,003 DEBUG [org.jboss.remoting.Client] Client[2120549:4p7205k-w1stw9-g38l7vx9-1-g38la78v-eq] is disconnected
                    12:30:34,003 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] removing callback handler ServerInvokerCallbackHandler[4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6q+4p72
                    05k-w1stw9-g38l7vx9-1-g38la5u3-7l]
                    12:30:34,003 DEBUG [org.jboss.remoting.Client] Client[5331451:4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6q].connect(null)
                    12:30:34,003 DEBUG [org.jboss.remoting.Client] Client[5331451:4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6q] connected to InvokerLocator [bisocket://169.254.0.200:866776360/callback?c
                    allbackServerHost=169.254.0.200&callbackServerPort=866776360&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWr
                    apper&datatype=jms&guid=4p7205k-w1stw9-g38l7vx9-1-g38la5rx-7c&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss
                    .jms.server.remoting.ServerSocketWrapper]
                    12:30:34,003 DEBUG [org.jboss.remoting.ServerInvoker] ServerInvoker (SocketServerInvoker[UNINITIALIZED]) removing client callback handler with session id of 4p7205k-w1stw9-g38
                    l7vx9-1-g38la5ov-6q+4p7205k-w1stw9-g38l7vx9-1-g38la5u3-7l.
                    12:30:34,003 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] unrecognized listener ID: 4p7205k-w1stw9-g38l7vx9-1-g38la5u3-7l
                    12:30:34,003 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@19e8474 from registry
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[5331451:4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6q] is disconnected
                    12:30:34,019 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:30:34,019 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@11ec4e7's count, current count 101
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[6505558:4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6q] is disconnected
                    12:30:34,019 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@1f1efce's count, current count 101
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[9429906:4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6r] is disconnected
                    12:30:34,019 DEBUG [org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection ConnectionEndpoint[d6-ln5al83g-1-9xv7l83g-9wts1w-k5027p4] with remo
                    ting session ID ...-g38la5it-4s
                    12:30:34,019 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@4a0e77 from registry
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[18698774:4p7205k-w1stw9-g38l7vx9-1-g38la5lu-62] is disconnected
                    12:30:34,019 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] removing callback handler ServerInvokerCallbackHandler[4p7205k-w1stw9-g38l7vx9-1-g38la5it-4s+4p72
                    05k-w1stw9-g38l7vx9-1-g38la5k4-5v]
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[33271547:4p7205k-w1stw9-g38l7vx9-1-g38la5it-4s].connect(null)
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[33271547:4p7205k-w1stw9-g38l7vx9-1-g38la5it-4s] connected to InvokerLocator [bisocket://169.254.0.200:857481459/callback?
                    callbackServerHost=169.254.0.200&callbackServerPort=857481459&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketW
                    rapper&datatype=jms&guid=4p7205k-w1stw9-g38l7vx9-1-g38la5j8-54&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jbos
                    s.jms.server.remoting.ServerSocketWrapper]
                    12:30:34,019 DEBUG [org.jboss.remoting.ServerInvoker] ServerInvoker (SocketServerInvoker[UNINITIALIZED]) removing client callback handler with session id of 4p7205k-w1stw9-g38
                    l7vx9-1-g38la5it-4s+4p7205k-w1stw9-g38l7vx9-1-g38la5k4-5v.
                    12:30:34,019 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] unrecognized listener ID: 4p7205k-w1stw9-g38l7vx9-1-g38la5k4-5v
                    12:30:34,019 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@1de2198 from registry
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[33271547:4p7205k-w1stw9-g38l7vx9-1-g38la5it-4s] is disconnected
                    12:30:34,019 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:30:34,019 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@11ec4e7's count, current count 100
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[18719185:4p7205k-w1stw9-g38l7vx9-1-g38la5it-4s] is disconnected
                    12:30:34,019 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@1f1efce's count, current count 100
                    12:30:34,019 DEBUG [org.jboss.remoting.Client] Client[27270070:4p7205k-w1stw9-g38l7vx9-1-g38la5it-4t] is disconnected
                    12:30:34,019 DEBUG [org.jboss.jms.server.connectionfactory.ConnectionFactoryJNDIMapper] Server[3].ConnFactoryJNDIMapper received notification from node 3
                    12:30:34,035 DEBUG [org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection ConnectionEndpoint[ss1-mldal83g-1-9xv7l83g-9wts1w-k5027p4] with rem
                    oting session ID ...-g38la69p-ar
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@fd12ba from registry
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[23034736:4p7205k-w1stw9-g38l7vx9-1-g38ladkq-1rb] is disconnected
                    12:30:34,035 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] removing callback handler ServerInvokerCallbackHandler[4p7205k-w1stw9-g38l7vx9-1-g38la69p-ar+4p72
                    05k-w1stw9-g38l7vx9-1-g38la780-em]
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[14185445:4p7205k-w1stw9-g38l7vx9-1-g38la69p-ar].connect(null)
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[14185445:4p7205k-w1stw9-g38l7vx9-1-g38la69p-ar] connected to InvokerLocator [bisocket://169.254.0.200:866360669/callback?
                    callbackServerHost=169.254.0.200&callbackServerPort=866360669&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketW
                    rapper&datatype=jms&guid=4p7205k-w1stw9-g38l7vx9-1-g38la74j-e8&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jbos
                    s.jms.server.remoting.ServerSocketWrapper]
                    12:30:34,035 DEBUG [org.jboss.remoting.ServerInvoker] ServerInvoker (SocketServerInvoker[UNINITIALIZED]) removing client callback handler with session id of 4p7205k-w1stw9-g38
                    l7vx9-1-g38la69p-ar+4p7205k-w1stw9-g38l7vx9-1-g38la780-em.
                    12:30:34,035 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] unrecognized listener ID: 4p7205k-w1stw9-g38l7vx9-1-g38la780-em
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@1d4ce42 from registry
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[14185445:4p7205k-w1stw9-g38l7vx9-1-g38la69p-ar] is disconnected
                    12:30:34,035 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@11ec4e7's count, current count 99
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[15209730:4p7205k-w1stw9-g38l7vx9-1-g38la69p-ar] is disconnected
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@1f1efce's count, current count 99
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[10312622:4p7205k-w1stw9-g38l7vx9-1-g38la69p-as] is disconnected
                    12:30:34,035 DEBUG [org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection ConnectionEndpoint[na-u86al83g-1-9xv7l83g-9wts1w-k5027p4] with remo
                    ting session ID ...-g38la5ma-63
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@9d8f8c from registry
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[17199068:4p7205k-w1stw9-g38l7vx9-1-g38la5wp-8l] is disconnected
                    12:30:34,035 DEBUG [org.jboss.jms.server.remoting.JMSServerInvocationHandler] removing callback handler ServerInvokerCallbackHandler[4p7205k-w1stw9-g38l7vx9-1-g38la5ma-63+4p72
                    05k-w1stw9-g38l7vx9-1-g38la5ov-6s]
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[3880389:4p7205k-w1stw9-g38l7vx9-1-g38la5ma-63].connect(null)
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[3880389:4p7205k-w1stw9-g38l7vx9-1-g38la5ma-63] connected to InvokerLocator [bisocket://169.254.0.200:861473485/callback?c
                    allbackServerHost=169.254.0.200&callbackServerPort=861473485&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWr
                    apper&datatype=jms&guid=4p7205k-w1stw9-g38l7vx9-1-g38la5ma-65&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss
                    .jms.server.remoting.ServerSocketWrapper]
                    12:30:34,035 DEBUG [org.jboss.remoting.ServerInvoker] ServerInvoker (SocketServerInvoker[UNINITIALIZED]) removing client callback handler with session id of 4p7205k-w1stw9-g38
                    l7vx9-1-g38la5ma-63+4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6s.
                    12:30:34,035 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] unrecognized listener ID: 4p7205k-w1stw9-g38l7vx9-1-g38la5ov-6s
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@11a24ee from registry
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[3880389:4p7205k-w1stw9-g38l7vx9-1-g38la5ma-63] is disconnected
                    12:30:34,035 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:30:34,035 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@11ec4e7's count, current count 98
                    12:30:34,035 DEBUG [org.jboss.remoting.Client] Client[30398857:4p7205k-w1stw9-g38l7vx9-1-g38la5ma-63] is disconnected
                    12:30:34,050 DEBUG [org.jboss.remoting.InvokerRegistry] decremented org.jboss.remoting.transport.local.LocalClientInvoker@1f1efce's count, current count 98
                    12:30:34,050 DEBUG [org.jboss.remoting.Client] Client[13816871:4p7205k-w1stw9-g38l7vx9-1-g38la5ma-64] is disconnected
                    12:30:34,050 INFO  [org.jboss.ejb3.EJBContainer] STOPPED EJB: de.schnittstellen.sap.alternativartikel.in.mq.SapAlternativArtikelInImpexMitteListener ejbName: SapAlternativArtikelInImpexMitteListener
                    12:30:34,050 INFO  [org.jboss.ejb3.EJBContainer] STOPPED EJB: de.schnittstellen.sap.alternativartikel.in.service.SapAlternativArtikelInImpexService ejbName: SapAlternativArtikelInImpexService
                    12:30:34,050 INFO  [org.jboss.ejb3.EJBContainer] STOPPED EJB: de.generation.komplett.service.AllGenerationCheckCompleteService ejbName: AllGenerationCheckCompleteService
                    12:32:09,327 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:32:09,327 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:34:19,323 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:34:19,323 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:35:35,994 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c0e346, bisocket://169.254.0.200:1608597621] disconnecting ...
                    12:35:35,994 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c0e346, bisocket://169.254.0.200:1608597621] disconnecting ...
                    12:35:35,994 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:35:35,994 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:35:35,994 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:35:35,994 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:35:35,994 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:35:35,994 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] stopped
                    12:36:29,321 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:36:29,321 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:38:39,321 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:38:39,321 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider
                    12:40:49,322 DEBUG [org.jboss.jms.server.recovery.MessagingXAResourceWrapper] Recover java:/DefaultJMSProvider

                    • 7. Re: Server shutdown is blocked in ClosedInterceptor
                      gaohoward

                      If you have any MDBs deployed, can you remove them also and try again?

                       

                      It looks like the JCA is trying to receive messages while the shut down thread is waiting for it to finish. So I'm thinking if there is no MDBs, and the problem is gone, that will confirm what I'm thinking.

                       

                      Thanks

                      • 8. Re: Server shutdown is blocked in ClosedInterceptor

                        Yes, I have MDBs. So I stopped the MDB instances manually via JMX console and the server shutdown was successful. Thank you for your help

                        to isolate the problem.

                        Is there a way to undeploy MDB automatically for shutdown? Maybe I can write a twiddle script to do this.

                        • 9. Re: Server shutdown is blocked in ClosedInterceptor
                          gaohoward

                          Re: Is there a way to undeploy MDB automatically for shutdown? Maybe I can write a twiddle script to do this.

                           

                          It's beyond me. I only know you can delete the jar from your deploy folder. Not sure if twiddle can handle this.

                          • 10. Re: Server shutdown is blocked in ClosedInterceptor

                            The twiddle approach was not successful. I got a deadlock at the same line in the ClosedInterceptor class after invocation of the stop or destroy method of the MDBs mbean.

                             

                            But I found the jira ticket

                            https://jira.jboss.org/jira/browse/JBMESSAGING-1743

                             

                            The problem looks very similar to my one.

                            @Howard:Do you think it's the same problem?

                            • 11. Re: Server shutdown is blocked in ClosedInterceptor
                              gaohoward

                              I don't think so. The deadlock is about a thread waiting for itself to return. It can be identified with the thread stack trace dump (as in the jira). But your stack trace doesn't suggest such a case.

                              • 12. Re: Server shutdown is blocked in ClosedInterceptor

                                sh twiddle.sh -s http://xx.xx.xx.xx:port/ invoke "jboss.system:service=MainDeployer" undeploy "file:////tmp/SMBPortal1.war"