QueueConnectionFactory.createQueueConnection is bloked
slogger May 5, 2008 4:20 PMI 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