3 Replies Latest reply on May 10, 2008 5:31 AM by timfox

    QueueConnectionFactory.createQueueConnection is bloked

    slogger

      I am using JBoss Messaging 1.4.0.SP3 on Jboss AS 4.2.1 GA (non-clustered installation).
      Jboss messaging uses remoting 2.2.2 SP7 (http://www.jboss.com/index.html?module=bb&op=viewtopic&t=134659).

      The JBoss Messaging configuration is defualt.


      The network connections are very unstable. Some period of time all works correctly, than receiving/sending stop working at all.

      For example, it has sample client code:

      @Test public void test() throws Exception {
       Properties props = new Properties();
       props.setProperty("java.naming.factory.initial", "org.jnp.interfaces.NamingContextFactory");
       props.setProperty("java.naming.provider.url", "10.0.0.166:1199");
       props.setProperty("java.naming.factory.url.pkgs", "org.jnp.interfaces");
       InitialContext jmsContext = new InitialContext(props);
       QueueConnectionFactory qcf = (QueueConnectionFactory) jmsContext.lookup("ConnectionFactory");
       log.trace("After lookup QueueConnectionFactory");
       QueueConnection connection = qcf.createQueueConnection(Sender.JMS_USER, Sender.JMS_USER_PWD);
       log.trace("After create QueueConnection");
       javax.jms.Queue queue = (javax.jms.Queue) jmsContext.lookup("queue/Region66");
       log.trace("After looked queue");
       QueueSession session = connection.createQueueSession(false, QueueSession.CLIENT_ACKNOWLEDGE);
       log.trace("After creating session");
       QueueReceiver receiver = session.createReceiver(queue);
       log.trace("After creating receiver");
       connection.start();
       log.trace("1");
       connection.close();
       log.trace("2");
       }


      It lasts to line -> log.trace("After lookup QueueConnectionFactory");

      Thus client code is bloked on this line:
      QueueConnection connection = qcf.createQueueConnection(Sender.JMS_USER, Sender.JMS_USER_PWD);

      It is client log:

      2008-05-05 19:49:42,734 DEBUG [com.guest.ejb.remote.TestFailed] After lookup QueueConnectionFactory
      2008-05-05 19:49:42,937 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
      2008-05-05 19:49:42,937 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] setting shouldCheckConnection to false
      2008-05-05 19:49:42,937 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] setting timeout to 0
      2008-05-05 19:49:42,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] constructed
      2008-05-05 19:49:42,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
      2008-05-05 19:49:42,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] setting shouldCheckConnection to false
      2008-05-05 19:49:42,953 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] setting timeout to 0
      2008-05-05 19:49:42,968 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] Setting ping frequency to: 214748364
      2008-05-05 19:49:42,984 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] connecting
      2008-05-05 19:49:42,984 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] added new pool ([]) as ServerAddress[10.0.0.166:4457, NO enableTcpNoDelay timeout 0 ms]
      2008-05-05 19:49:42,984 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] connected
      2008-05-05 19:49:43,140 TRACE [org.jboss.jms.client.delegate.DelegateSupport] ConnectionFactoryDelegate[jboss.messaging.connectionfactory:service=ConnectionFactory, SID=0] invoking ConnectionFactoryGetClientAOPStackRequest[a17083] synchronously on server using Client[14800362]
      2008-05-05 19:49:43,140 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457](1) invoking InvocationRequest[a31e1b, JMS, ConnectionFactoryGetClientAOPStackRequest[a17083]]
      2008-05-05 19:49:43,156 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] getting a socket, usedPooled: 0
      2008-05-05 19:49:43,156 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] creating socket 0, attempt 1
      2008-05-05 19:49:43,156 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] created socket: Socket[addr=/10.0.0.166,port=4457,localport=3393]
      2008-05-05 19:49:43,171 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] constructing org.jboss.jms.client.remoting.ClientSocketWrapper instance for Socket[addr=/10.0.0.166,port=4457,localport=3393], using timeout 0
      2008-05-05 19:49:43,171 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403] setting timeout to 0
      2008-05-05 19:49:43,171 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] writing version 22 on output stream
      2008-05-05 19:49:43,171 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] writing invocation to marshaller
      2008-05-05 19:49:43,171 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationRequest[a31e1b, JMS, ConnectionFactoryGetClientAOPStackRequest[a17083]]
      2008-05-05 19:49:43,187 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:49:43,187 TRACE [org.jboss.jms.wireformat.JMSWireFormat] JBM Request
      2008-05-05 19:49:43,187 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: ConnectionFactoryGetClientAOPStackRequest[a17083]
      2008-05-05 19:49:43,187 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:49:43,187 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] done writing invocation to marshaller
      2008-05-05 19:49:43,187 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] reading version from input stream
      2008-05-05 19:49:43,187 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] read version 22 from input stream
      2008-05-05 19:49:43,187 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] reading response from unmarshaller
      2008-05-05 19:49:43,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:49:43,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:49:43,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet ConnectionFactoryGetClientAOPStackResponse[null]
      2008-05-05 19:49:43,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:49:43,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:49:43,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationResponse[17653ae, ConnectionFactoryGetClientAOPStackResponse[18618 bytes]]
      2008-05-05 19:49:43,203 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] returned ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403] to pool
      2008-05-05 19:49:43,203 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] received response InvocationResponse[17653ae, ConnectionFactoryGetClientAOPStackResponse[18618 bytes]]
      2008-05-05 19:49:43,203 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[1e13d52, bisocket://10.0.0.166:4457] received InvocationResponse so going to return response's return value of ConnectionFactoryGetClientAOPStackResponse[18618 bytes]
      2008-05-05 19:49:43,218 TRACE [org.jboss.jms.client.delegate.DelegateSupport] ConnectionFactoryDelegate[jboss.messaging.connectionfactory:service=ConnectionFactory, SID=0] got server response for ConnectionFactoryGetClientAOPStackRequest[a17083]: ConnectionFactoryGetClientAOPStackResponse[18618 bytes]
      2008-05-05 19:49:43,937 TRACE [org.jboss.jms.client.remoting.JMSRemotingConnection] JMSRemotingConnection[bisocket://10.0.0.166:4457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=10000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat] created
      2008-05-05 19:49:43,937 TRACE [org.jboss.jms.client.remoting.JMSRemotingConnection] JMSRemotingConnection[bisocket://10.0.0.166:4457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=10000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat] created client
      2008-05-05 19:49:43,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting maxPoolSize to 200
      2008-05-05 19:49:43,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
      2008-05-05 19:49:43,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting shouldCheckConnection to false
      2008-05-05 19:49:43,953 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting timeout to 0
      2008-05-05 19:49:43,953 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] constructed
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting maxPoolSize to 200
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting shouldCheckConnection to false
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] setting timeout to 0
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] Setting ping frequency to: 214748364
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] connecting
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] using pool ([ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403]]) already defined for ServerAddress[10.0.0.166:4457, NO enableTcpNoDelay timeout 0 ms]
      2008-05-05 19:49:43,968 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] connected
      2008-05-05 19:49:43,984 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] sending initial lease ping to server to determine if server has leasing enabled.
      2008-05-05 19:49:43,984 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](1) invoking InvocationRequest[1113622, $PING$]
      2008-05-05 19:49:43,984 TRACE [org.jboss.remoting.marshal.MarshalFactory] Could not find marshaller for data type 'jms'. Object in collection is null
      2008-05-05 19:49:44,000 TRACE [org.jboss.remoting.marshal.MarshalFactory] Could not look up marshaller by data type ('jms'). Will try to load dynamically.
      2008-05-05 19:49:44,000 TRACE [org.jboss.remoting.marshal.MarshalFactory] Found marshaller by loading locally.
      2008-05-05 19:49:44,000 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reusing pooled connection: ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403]
      2008-05-05 19:49:44,000 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] got a socket, usedPooled: 1
      2008-05-05 19:49:44,000 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing version 22 on output stream
      2008-05-05 19:49:44,000 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing invocation to marshaller
      2008-05-05 19:49:44,000 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationRequest[1113622, $PING$]
      2008-05-05 19:49:44,000 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:49:44,015 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationRequest[1113622, $PING$]]
      2008-05-05 19:49:44,015 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:49:44,015 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] done writing invocation to marshaller
      2008-05-05 19:49:44,015 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading version from input stream
      2008-05-05 19:49:44,015 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] read version 22 from input stream
      2008-05-05 19:49:44,015 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading response from unmarshaller
      2008-05-05 19:49:44,015 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:49:44,015 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:49:44,015 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:49:44,031 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:49:44,031 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:49:44,031 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationResponse[18bf072, InvocationResponse[56f631, true]]
      2008-05-05 19:49:44,031 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] returned ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403] to pool
      2008-05-05 19:49:44,031 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received response InvocationResponse[18bf072, InvocationResponse[56f631, true]]
      2008-05-05 19:49:44,046 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received InvocationResponse so going to return response's return value of InvocationResponse[56f631, true]
      2008-05-05 19:49:44,046 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] server does have leasing enabled (with default lease period of 10000) and will start a new lease pinger.
      2008-05-05 19:49:44,046 TRACE [org.jboss.remoting.LeasePinger] LeasePinger[SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)] adding new client with session ID a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4 and lease period 10000
      2008-05-05 19:49:44,062 TRACE [org.jboss.remoting.LeasePinger] LeasePinger[SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)] sending ping to server. Currently managing lease for following clients:
       a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4
      
      2008-05-05 19:49:44,062 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](1) invoking InvocationRequest[26dbec, $PING$]
      2008-05-05 19:49:44,062 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reusing pooled connection: ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403]
      2008-05-05 19:49:44,062 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] got a socket, usedPooled: 1
      2008-05-05 19:49:44,062 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing version 22 on output stream
      2008-05-05 19:49:44,062 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing invocation to marshaller
      2008-05-05 19:49:44,062 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationRequest[26dbec, $PING$]
      2008-05-05 19:49:44,078 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:49:44,078 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationRequest[26dbec, $PING$]]
      2008-05-05 19:49:44,078 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:49:44,078 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] done writing invocation to marshaller
      2008-05-05 19:49:44,078 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading version from input stream
      2008-05-05 19:49:44,093 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] read version 22 from input stream
      2008-05-05 19:49:44,093 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading response from unmarshaller
      2008-05-05 19:49:44,093 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:49:44,093 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:49:44,093 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:49:44,093 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:49:44,093 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:49:44,093 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationResponse[2af081, InvocationResponse[113a53d, true]]
      2008-05-05 19:49:44,093 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] returned ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403] to pool
      2008-05-05 19:49:44,093 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received response InvocationResponse[2af081, InvocationResponse[113a53d, true]]
      2008-05-05 19:49:44,109 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received InvocationResponse so going to return response's return value of InvocationResponse[113a53d, true]
      2008-05-05 19:49:44,109 TRACE [org.jboss.remoting.LeasePinger] LeasePinger[SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)] successfully pinged the server
      2008-05-05 19:49:44,109 TRACE [org.jboss.remoting.LeasePinger] LeasePinger[SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)] starting lease timer with ping period of 10000
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting maxPoolSize to 1
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting shouldCheckConnection to false
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting timeout to 0
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] constructed
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting maxPoolSize to 1
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting shouldCheckConnection to false
      2008-05-05 19:49:44,125 DEBUG [org.jboss.remoting.transport.socket.SocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] setting timeout to 0
      2008-05-05 19:49:44,140 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] Setting ping frequency to: 214748364
      2008-05-05 19:49:44,140 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] connecting
      2008-05-05 19:49:44,140 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] using pool ([ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403]]) already defined for ServerAddress[10.0.0.166:4457, NO enableTcpNoDelay timeout 0 ms]
      2008-05-05 19:49:44,140 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[c5495e, bisocket://10.0.0.166:4457] connected
      2008-05-05 19:49:44,140 TRACE [org.jboss.jms.client.remoting.JMSRemotingConnection] JMSRemotingConnection[bisocket://10.0.0.166:4457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=10000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat] is doing push callbacks
      2008-05-05 19:49:44,140 DEBUG [org.jboss.remoting.Client] starting callback Connector: InvokerLocator [bisocket://10.0.0.226:1489232572/callback?guid=a006a-zg7j8n-ffv8ao6l-1-ffv8ap8s-8&callbackServerProtocol=bisocket&callbackServerHost=10.0.0.226&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper&datatype=jms&callbackServerPort=1489232572&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&isCallbackServer=true]
      2008-05-05 19:49:44,250 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] did not find server socket factory configuration as mbean service or classname. Creating default server socket factory.
      2008-05-05 19:49:44,250 DEBUG [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] created server socket factory javax.net.DefaultServerSocketFactory@f9c40
      2008-05-05 19:49:44,250 DEBUG [org.jboss.remoting.transport.Connector] org.jboss.remoting.transport.Connector@71dc3d started
      2008-05-05 19:49:44,265 TRACE [org.jboss.remoting.transport.local.LocalClientInvoker] Using local client invoker for invocation.
      2008-05-05 19:49:44,265 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] received InternalInvocation[110c31]
      2008-05-05 19:49:44,265 TRACE [org.jboss.remoting.ServerInvoker] handling InternalInvocation where method name = addClientListener
      2008-05-05 19:49:44,281 DEBUG [org.jboss.remoting.ServerInvoker] ServerInvoker (SocketServerInvoker[UNINITIALIZED]) added client callback handler CallbackManager[787d6a] with session id of a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4+a006a-zg7j8n-ffv8ao6l-1-ffv8apbu-9 and callback handle object of null.
      2008-05-05 19:49:44,281 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[UNINITIALIZED] successfully dispatched invocation, returning null from subsystem 'JMS' to client a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4
      2008-05-05 19:49:44,281 TRACE [org.jboss.remoting.InvokerRegistry] destroying client invoker InvokerLocator [bisocket://10.0.0.226:1489232572/callback?callbackServerHost=10.0.0.226&callbackServerPort=1489232572&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=a006a-zg7j8n-ffv8ao6l-1-ffv8ap8s-8&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper], config {}
      2008-05-05 19:49:44,281 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.transport.local.LocalClientInvoker@1976011 from registry
      2008-05-05 19:49:44,296 TRACE [org.jboss.remoting.InvokerRegistry] disconnecting org.jboss.remoting.transport.local.LocalClientInvoker@1976011
      2008-05-05 19:49:44,296 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](1) invoking InvocationRequest[1878144, JMS, InternalInvocation[137d090]]
      2008-05-05 19:49:44,296 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] getting secondary locator
      2008-05-05 19:49:44,296 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](1) invoking InvocationRequest[15db314, InternalInvocation[97eded]]
      2008-05-05 19:49:44,296 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reusing pooled connection: ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403]
      2008-05-05 19:49:44,296 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] got a socket, usedPooled: 1
      2008-05-05 19:49:44,296 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing version 22 on output stream
      2008-05-05 19:49:44,312 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing invocation to marshaller
      2008-05-05 19:49:44,312 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationRequest[15db314, InternalInvocation[97eded]]
      2008-05-05 19:49:44,312 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:49:44,312 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationRequest[15db314, InternalInvocation[97eded]]]
      2008-05-05 19:49:44,312 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:49:44,312 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] done writing invocation to marshaller
      2008-05-05 19:49:44,312 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading version from input stream
      2008-05-05 19:49:44,312 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] read version 22 from input stream
      2008-05-05 19:49:44,328 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading response from unmarshaller
      2008-05-05 19:49:44,328 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:49:44,328 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:49:44,328 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:49:44,328 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:49:44,328 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:49:44,328 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationResponse[16f144c, InvokerLocator [null://10.0.0.166:2737/null]]
      2008-05-05 19:49:44,328 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] returned ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403] to pool
      2008-05-05 19:49:44,328 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received response InvocationResponse[16f144c, InvokerLocator [null://10.0.0.166:2737/null]]
      2008-05-05 19:49:44,343 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received InvocationResponse so going to return response's return value of InvokerLocator [null://10.0.0.166:2737/null]
      2008-05-05 19:49:44,343 DEBUG [org.jboss.remoting.transport.bisocket.BisocketClientInvoker] secondary locator: InvokerLocator [null://10.0.0.166:2737/null]
      2008-05-05 19:49:44,343 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] creating control connection: InvokerLocator [null://10.0.0.166:2737/null]
      2008-05-05 19:49:44,343 DEBUG [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] created control connection: Socket[addr=/10.0.0.166,port=2737,localport=3394]
      2008-05-05 19:49:44,359 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reusing pooled connection: ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3393].698403]
      2008-05-05 19:49:44,359 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] got a socket, usedPooled: 1
      2008-05-05 19:49:44,359 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing version 22 on output stream
      2008-05-05 19:49:44,359 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing invocation to marshaller
      2008-05-05 19:49:44,359 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationRequest[1878144, JMS, InternalInvocation[137d090]]
      2008-05-05 19:49:44,375 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:49:44,375 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationRequest[1878144, JMS, InternalInvocation[137d090]]]
      2008-05-05 19:49:44,375 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:49:44,375 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] done writing invocation to marshaller
      2008-05-05 19:49:44,390 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading version from input stream
      2008-05-05 19:49:54,109 TRACE [org.jboss.remoting.LeasePinger] LeasePinger[SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)] sending ping to server. Currently managing lease for following clients:
       a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4
      
      2008-05-05 19:49:54,109 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](1) invoking InvocationRequest[aadc97, $PING$]
      2008-05-05 19:49:54,109 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] getting a socket, usedPooled: 1
      2008-05-05 19:49:54,109 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] creating socket 1, attempt 1
      2008-05-05 19:49:54,125 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] created socket: Socket[addr=/10.0.0.166,port=4457,localport=3395]
      2008-05-05 19:49:54,125 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] constructing org.jboss.jms.client.remoting.ClientSocketWrapper instance for Socket[addr=/10.0.0.166,port=4457,localport=3395], using timeout 0
      2008-05-05 19:49:54,125 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3395].178460d] setting timeout to 0
      2008-05-05 19:49:54,125 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing version 22 on output stream
      2008-05-05 19:49:54,125 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] writing invocation to marshaller
      2008-05-05 19:49:54,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationRequest[aadc97, $PING$]
      2008-05-05 19:49:54,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:49:54,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationRequest[aadc97, $PING$]]
      2008-05-05 19:49:54,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:49:54,140 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] done writing invocation to marshaller
      2008-05-05 19:49:54,140 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading version from input stream
      2008-05-05 19:49:54,140 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] read version 22 from input stream
      2008-05-05 19:49:54,140 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] reading response from unmarshaller
      2008-05-05 19:49:54,140 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:49:54,140 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:49:54,140 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:49:54,140 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:49:54,140 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:49:54,140 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationResponse[bac9b9, InvocationResponse[111b910, true]]
      2008-05-05 19:49:54,140 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] returned ClientSocketWrapper[Socket[addr=/10.0.0.166,port=4457,localport=3395].178460d] to pool
      2008-05-05 19:49:54,156 TRACE [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received response InvocationResponse[bac9b9, InvocationResponse[111b910, true]]
      2008-05-05 19:49:54,156 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457] received InvocationResponse so going to return response's return value of InvocationResponse[111b910, true]
      2008-05-05 19:49:54,156 TRACE [org.jboss.remoting.LeasePinger] LeasePinger[SocketClientInvoker[e1899b, bisocket://10.0.0.166:4457](a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)] successfully pinged the server
      
      



      It is repeated periodically during the unlimited time.


      It is server log:

      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] accepted Socket[addr=/10.0.0.226,port=3393,localport=4457]
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] trying to get a worker thread from threadpool for processing
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] got WorkerThread#26[10.0.0.226:3334] from threadpool
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] reusing WorkerThread#26[10.0.0.226:3334]
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#26[10.0.0.226:3393] has notified on mutex
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] passed through ServerSocketRefresh.release()
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#26[10.0.0.226:3393] woke up after wait
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] is going to wait on serverSocket.accept()
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] beginning dorun()
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating the socket wrapper
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] constructing org.jboss.jms.server.remoting.ServerSocketWrapper instance for Socket[addr=/10.0.0.226,port=3393,localport=4457], using timeout 0
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/10.0.0.226,port=3393,localport=4457].11792ef] setting timeout to 0
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] processing first invocation without acknowledging
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:33,281 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet ConnectionFactoryGetClientAOPStackRequest[afc0dd]
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[9f0102, JMS, ConnectionFactoryGetClientAOPStackRequest[afc0dd]]
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[9f0102, JMS, ConnectionFactoryGetClientAOPStackRequest[afc0dd]] from unmarshaller
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received ConnectionFactoryGetClientAOPStackRequest[afc0dd]
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] dispatching InvocationRequest[9f0102, JMS, ConnectionFactoryGetClientAOPStackRequest[afc0dd]] from client null to subsystem 'JMS'
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.server.remoting.JMSServerInvocationHandler] invoking InvocationRequest[9f0102, JMS, ConnectionFactoryGetClientAOPStackRequest[afc0dd]]
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] successfully dispatched invocation, returning ConnectionFactoryGetClientAOPStackResponse[18618 bytes] from subsystem 'JMS' to client null
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned ConnectionFactoryGetClientAOPStackResponse[18618 bytes]
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[fb59cf, ConnectionFactoryGetClientAOPStackResponse[18618 bytes]]
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] JBM Response
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: ConnectionFactoryGetClientAOPStackResponse[18618 bytes]
      2008-05-05 19:53:33,296 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:33,296 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[1c54b7e, $PING$]
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[1c54b7e, $PING$] from unmarshaller
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received $PING$
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for client session id: a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.Lease] Starting lease for client invoker (session id = a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6) with lease window time of 20000
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.ServerInvoker] No lease established for client session id (a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6), so starting a new one.
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] returning InvocationResponse[1df5bda, true]
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned InvocationResponse[1df5bda, true]
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[107506d, InvocationResponse[1df5bda, true]]
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationResponse[107506d, InvocationResponse[1df5bda, true]]]
      2008-05-05 19:53:34,125 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:34,125 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[1b1d760, $PING$]
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[1b1d760, $PING$] from unmarshaller
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received $PING$
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for client session id: a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.ServerInvoker] Updated lease for client session id (a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] returning InvocationResponse[b30152, true]
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned InvocationResponse[b30152, true]
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[1bafe0, InvocationResponse[b30152, true]]
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationResponse[1bafe0, InvocationResponse[b30152, true]]]
      2008-05-05 19:53:34,203 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:34,203 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[17c295b, InternalInvocation[7f1b41]]
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[17c295b, InternalInvocation[7f1b41]] from unmarshaller
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received InternalInvocation[7f1b41]
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] successfully dispatched invocation, returning InvokerLocator [null://10.0.0.166:2737/null] from subsystem 'null' to client null
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned InvokerLocator [null://10.0.0.166:2737/null]
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[d64ab5, InvokerLocator [null://10.0.0.166:2737/null]]
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationResponse[d64ab5, InvokerLocator [null://10.0.0.166:2737/null]]]
      2008-05-05 19:53:34,421 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:34,421 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:34,500 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:34,500 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:34,500 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:34,500 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:34,500 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:53:34,500 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:34,500 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:34,500 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[c2cc2c, JMS, InternalInvocation[ea8e55]]
      2008-05-05 19:53:34,500 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[c2cc2c, JMS, InternalInvocation[ea8e55]] from unmarshaller
      2008-05-05 19:53:34,500 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:34,500 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received InternalInvocation[ea8e55]
      2008-05-05 19:53:34,500 TRACE [org.jboss.remoting.ServerInvoker] handling InternalInvocation where method name = addListener
      2008-05-05 19:53:34,500 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] Session id for callback handler is a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4+a006a-zg7j8n-ffv8ao6l-1-ffv8apbu-9
      2008-05-05 19:53:34,500 DEBUG [org.jboss.remoting.callback.DefaultCallbackErrorHandler] DefaultCallbackErrorHandler[UNITIALIZED] setting server invoker to SocketServerInvoker[10.0.0.166:4457]
      2008-05-05 19:53:34,500 DEBUG [org.jboss.remoting.callback.DefaultCallbackErrorHandler] DefaultCallbackErrorHandler[SocketServerInvoker[10.0.0.166:4457]] setting callback handler to ServerInvokerCallbackHandler[a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-4+a006a-zg7j8n-ffv8ao6l-1-ffv8apbu-9]
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] accepted Socket[addr=/10.0.0.226,port=3395,localport=4457]
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] trying to get a worker thread from threadpool for processing
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] got WorkerThread#24[10.0.0.188:38263] from threadpool
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] reusing WorkerThread#24[10.0.0.188:38263]
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#24[10.0.0.226:3395] has notified on mutex
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] passed through ServerSocketRefresh.release()
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] WorkerThread#24[10.0.0.226:3395] woke up after wait
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketServerInvoker] SocketServerInvoker[10.0.0.166:4457] is going to wait on serverSocket.accept()
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] beginning dorun()
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating the socket wrapper
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] constructing org.jboss.jms.server.remoting.ServerSocketWrapper instance for Socket[addr=/10.0.0.226,port=3395,localport=4457], using timeout 0
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.SocketWrapper] ServerSocketWrapper[Socket[addr=/10.0.0.226,port=3395,localport=4457].126792d] setting timeout to 0
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] processing first invocation without acknowledging
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:44,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[dd9397, $PING$]
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[dd9397, $PING$] from unmarshaller
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received $PING$
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for client session id: a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.ServerInvoker] Updated lease for client session id (a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] returning InvocationResponse[104b063, true]
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned InvocationResponse[104b063, true]
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[d8341a, InvocationResponse[104b063, true]]
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationResponse[d8341a, InvocationResponse[104b063, true]]]
      2008-05-05 19:53:44,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:44,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[692fe3, $PING$]
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[692fe3, $PING$] from unmarshaller
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received $PING$
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for client session id: a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.ServerInvoker] Updated lease for client session id (a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] returning InvocationResponse[1c7011e, true]
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned InvocationResponse[1c7011e, true]
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[1a7634, InvocationResponse[1c7011e, true]]
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationResponse[1a7634, InvocationResponse[1c7011e, true]]]
      2008-05-05 19:53:54,250 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:53:54,250 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Returning payload: InvocationRequest[d56b9d, $PING$]
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[d56b9d, $PING$] from unmarshaller
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[10.0.0.166:4457].invoke()
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] received $PING$
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for client session id: a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.ServerInvoker] Updated lease for client session id (a006a-zg7j8n-ffv8ao6l-1-ffv8ap35-6)
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[10.0.0.166:4457] returning InvocationResponse[18c410f, true]
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[10.0.0.166:4457].invoke() returned InvocationResponse[18c410f, true]
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing InvocationResponse[10346bb, InvocationResponse[18c410f, true]]
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is a DataOutputStream
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Writing packet: SerializedPacket[InvocationResponse[10346bb, InvocationResponse[18c410f, true]]]
      2008-05-05 19:54:04,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Wrote packet
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation
      2008-05-05 19:54:04,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream
      2008-05-05 19:54:14,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream
      2008-05-05 19:54:14,234 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller
      2008-05-05 19:54:14,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading
      2008-05-05 19:54:14,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Stream is already DataInputStream :)
      2008-05-05 19:54:14,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Created packet SerializedPacket[null]
      2008-05-05 19:54:14,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Reading packet
      2008-05-05 19:54:14,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Read packet
      2008-05-05 19:54:14,234 TRACE [org.jboss.jms.wireformat.JMSWireFormat] Retur