Message receiver connot reconnect after the messaging server

[gurwinder]

Hi,

I am using JBoss Messaging 1.2.0.sp1. I have an application that listens for messages on a JBM queue, and processes those messages.

The problem is that if the messaging server gets restarted, the message receiver in my application fails to reconnect with the messaging server.

I even wrapped the Consumer.receive() call in a try/catch block to handle throwable, but it never throws any exceptions or errors, it just gets stuck in the Consumer.receive() call. If I send messages to that queue, the receiver does not pick up those messages. Only after I restart my application, it picks up those messages.

Is there a configuration property that would configure the client so that it keeps retrying to connect to the messaging server? Am I missing something or is it a bug in JBoss Messaging? I will appreciate any help.

Here is my test code for testing this scenario:

public void testMessagingReconnect() {
while (true) {
try {
Hashtable env = new Hashtable();
env.put(Context.PROVIDER_URL, "jnp://localhost:1199");
env.put(Context.INITIAL_CONTEXT_FACTORY,
"org.jboss.naming.NamingContextFactory");

InitialContext ic = new InitialContext(env);
ConnectionFactory cf = (ConnectionFactory) ic
.lookup("java:/ConnectionFactory");

Connection connection = cf.createConnection();
Session session2 = connection.createSession(false,
Session.CLIENT_ACKNOWLEDGE);
Queue queue = session2.createQueue("testQueue");

MessageConsumer consumer = session2.createConsumer(queue);
connection.start();
System.out.println("Listening");
TextMessage message = (TextMessage) consumer.receive();
System.out.println("Received message : " + message.getText());
message.acknowledge();
} catch (Throwable e) {
System.out.println("An error occured.");
e.printStackTrace();
// reconnect after 5 seconds
try {
Thread.sleep(5000);
} catch (InterruptedException e1) {
e1.printStackTrace();
}
}
}
}

Here are the output logs:

2007-05-08 15:43:27,693[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] setting maxPoolSize to 50
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] setting shouldCheckConnection to false
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] constructed
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] setting maxPoolSize to 50
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] setting shouldCheckConnection to false
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] connecting
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] added new pool ([]) as ServerAddress[159.125.194.87:4557, NO enableTcpNoDelay timeout 0 ms]
2007-05-08 15:43:27,708[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[1d6f122, bisocket://159.125.194.87:4557] connected
2007-05-08 15:43:29,115[main] DEBUG org.jboss.jms.client.remoting.JMSRemotingConnection - JMSRemotingConnection[bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] created
2007-05-08 15:43:29,130[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] setting maxPoolSize to 50
2007-05-08 15:43:29,130[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
2007-05-08 15:43:29,130[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] setting shouldCheckConnection to false
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] constructed
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] setting maxPoolSize to 50
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] setting shouldCheckConnection to false
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] connecting
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] using pool ([ClientSocketWrapper[Socket[addr=/159.125.194.87,port=4557,localport=2997].ef83d3]]) already defined for ServerAddress[159.125.194.87:4557, NO enableTcpNoDelay timeout 0 ms]
2007-05-08 15:43:29,146[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] connected
2007-05-08 15:43:29,271[main] DEBUG org.jboss.jms.client.remoting.JMSRemotingConnection - JMSRemotingConnection[bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] is doing push callbacks
2007-05-08 15:43:29,271[main] DEBUG org.jboss.remoting.Client - starting callback Connector: InvokerLocator [bisocket://159.125.194.87:742937582/callback?serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper&isCallbackServer=true&callbackServerProtocol=bisocket&datatype=jms&guid=4f3h5e2f-76or01-f1grt1rk-1-f1grt33r-6&callbackServerHost=159.125.194.87&callbackServerPort=742937582&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serializationtype=jms&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper]
2007-05-08 15:43:29,396[main] DEBUG org.jboss.remoting.ServerInvoker - SocketServerInvoker[UNINITIALIZED] did not find server socket factory configuration as mbean service or classname. Creating default server socket factory.
2007-05-08 15:43:29,396[main] DEBUG org.jboss.remoting.ServerInvoker - SocketServerInvoker[UNINITIALIZED] created server socket factory javax.net.DefaultServerSocketFactory@83b1b
2007-05-08 15:43:29,396[main] DEBUG org.jboss.remoting.transport.Connector - org.jboss.remoting.transport.Connector@7e8c4d started
2007-05-08 15:43:29,427[main] DEBUG org.jboss.remoting.ServerInvoker - ServerInvoker (SocketServerInvoker[UNINITIALIZED]) added client callback handler CallbackManager[16dc861] with session id of 4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-4+4f3h5e2f-76or01-f1grt1rk-1-f1grt37n-7 and callback handle object of null.
2007-05-08 15:43:29,427[main] DEBUG org.jboss.remoting.InvokerRegistry - removed org.jboss.remoting.transport.local.LocalClientInvoker@139e351 from registry
2007-05-08 15:43:29,427[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - getting secondary locator
2007-05-08 15:43:29,427[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - secondary locator: InvokerLocator [null://159.125.194.87:2837/null]
2007-05-08 15:43:29,427[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketServerInvoker - creating control connection: InvokerLocator [null://159.125.194.87:2837/null]
2007-05-08 15:43:29,443[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketServerInvoker - created control connection: Socket[addr=/159.125.194.87,port=2837,localport=2998]
2007-05-08 15:43:29,443[main] DEBUG org.jboss.jms.client.remoting.JMSRemotingConnection - JMSRemotingConnection[bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] started
2007-05-08 15:43:29,677[main] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[null, pingPeriod=2000 ms] created
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting maxPoolSize to 50
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting shouldCheckConnection to false
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.SocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting timeout to 1000
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] constructed
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting maxPoolSize to 50
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting shouldCheckConnection to false
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.SocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] setting timeout to 1000
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] connecting
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] added new pool ([]) as ServerAddress[159.125.194.87:4557, NO enableTcpNoDelay timeout 1000 ms]
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] connected
2007-05-08 15:43:29,708[main] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557], pingPeriod=2000 ms] started
2007-05-08 15:43:29,708[main] DEBUG org.jboss.jms.message.MessageIdGeneratorFactory - checked out MessageIdGenerator for 0, reference count is 1
2007-05-08 15:43:30,286[main] DEBUG org.jboss.jms.client.JBossSession - attempting to create consumer for destination:JBossQueue[testQueue]
Listening
2007-05-08 15:43:30,505[control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketServerInvoker - created: WorkerThread#0[159.125.194.87:2837]
2007-05-08 15:43:30,552[WorkerThread#0[159.125.194.87:2837]] DEBUG org.jboss.remoting.ServerInvoker - Thread pool class supplied is not an object name.
Received message : hello
2007-05-08 15:43:30,740[main] DEBUG org.jboss.jms.client.remoting.JMSRemotingConnection - JMSRemotingConnection[bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] created
2007-05-08 15:43:30,755[main] DEBUG org.jboss.remoting.MicroRemoteClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] added client with session ID 4f3h5e2f-76or01-f1grt1rk-1-f1grt48k-b to the lease pinger
2007-05-08 15:43:30,755[main] DEBUG org.jboss.jms.client.remoting.JMSRemotingConnection - JMSRemotingConnection[bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] is doing push callbacks
2007-05-08 15:43:30,755[main] DEBUG org.jboss.remoting.Client - starting callback Connector: InvokerLocator [bisocket://159.125.194.87:741857373/callback?serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper&isCallbackServer=true&callbackServerProtocol=bisocket&datatype=jms&guid=4f3h5e2f-76or01-f1grt1rk-1-f1grt48z-c&callbackServerHost=159.125.194.87&callbackServerPort=741857373&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serializationtype=jms&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper]
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.ServerInvoker - SocketServerInvoker[UNINITIALIZED] did not find server socket factory configuration as mbean service or classname. Creating default server socket factory.
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.ServerInvoker - SocketServerInvoker[UNINITIALIZED] created server socket factory javax.net.DefaultServerSocketFactory@83b1b
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.transport.Connector - org.jboss.remoting.transport.Connector@1192059 started
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.ServerInvoker - ServerInvoker (SocketServerInvoker[UNINITIALIZED]) added client callback handler CallbackManager[8b058b] with session id of 4f3h5e2f-76or01-f1grt1rk-1-f1grt48k-b+4f3h5e2f-76or01-f1grt1rk-1-f1grt49f-d and callback handle object of null.
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.InvokerRegistry - removed org.jboss.remoting.transport.local.LocalClientInvoker@132021a from registry
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - getting secondary locator
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - secondary locator: InvokerLocator [null://159.125.194.87:2837/null]
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketServerInvoker - creating control connection: InvokerLocator [null://159.125.194.87:2837/null]
2007-05-08 15:43:30,771[main] DEBUG org.jboss.remoting.transport.bisocket.BisocketServerInvoker - created control connection: Socket[addr=/159.125.194.87,port=2837,localport=3000]
2007-05-08 15:43:30,787[main] DEBUG org.jboss.jms.client.remoting.JMSRemotingConnection - JMSRemotingConnection[bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] started
2007-05-08 15:43:30,787[main] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[null, pingPeriod=2000 ms] created
2007-05-08 15:43:30,787[main] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557], pingPeriod=2000 ms] started
2007-05-08 15:43:30,787[main] DEBUG org.jboss.jms.message.MessageIdGeneratorFactory - checked out MessageIdGenerator for 0, reference count is 2
2007-05-08 15:43:30,787[main] DEBUG org.jboss.jms.client.JBossSession - attempting to create consumer for destination:JBossQueue[testQueue]
Listening
2007-05-08 15:43:43,631[WorkerThread#0[159.125.194.87:2837]] DEBUG org.jboss.remoting.transport.socket.ServerThread - WorkerThread#0[159.125.194.87:2837] closing socketWrapper: ServerSocketWrapper[Socket[addr=/159.125.194.87,port=2837,localport=2999].fb6c5f]
2007-05-08 15:43:43,646[WorkerThread#0[159.125.194.87:2837]] DEBUG org.jboss.jms.server.remoting.ServerSocketWrapper - wrote CLOSING byte
2007-05-08 15:43:43,646[WorkerThread#0[159.125.194.87:2837]] DEBUG org.jboss.remoting.transport.socket.SocketWrapper - ServerSocketWrapper[Socket[addr=/159.125.194.87,port=2837,localport=2999].fb6c5f] closing
2007-05-08 15:43:43,725[Timer-2] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator failed to ping via SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557]
org.jboss.remoting.ServerInvoker$InvalidStateException: Can not process invocation request since is not in started state.
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:745)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:553)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:163)
at org.jboss.remoting.ConnectionValidator.doCheckConnection(ConnectionValidator.java:126)
at org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:195)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
2007-05-08 15:43:43,740[Timer-2] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557], pingPeriod=2000 ms]'s connections is invalid
2007-05-08 15:43:43,740[Timer-2] DEBUG org.jboss.remoting.InvokerRegistry - decremented SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557]'s count, current count 1
2007-05-08 15:43:43,740[Timer-2] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557], pingPeriod=2000 ms] stopped, returning true
2007-05-08 15:43:44,287[Timer-0] DEBUG org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server
org.jboss.remoting.ServerInvoker$InvalidStateException: Can not process invocation request since is not in started state.
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:745)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:553)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:163)
at org.jboss.remoting.LeasePinger.sendClientPing(LeasePinger.java:283)
at org.jboss.remoting.LeasePinger.access$000(LeasePinger.java:20)
at org.jboss.remoting.LeasePinger$LeaseTimerTask.run(LeasePinger.java:315)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
2007-05-08 15:43:44,287[Timer-0] WARN org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server: Can not process invocation request since is not in started state.
2007-05-08 15:43:44,787[Timer-2] DEBUG org.jboss.remoting.transport.socket.SocketWrapper - ClientSocketWrapper[Socket[addr=/159.125.194.87,port=4557,localport=3001].127f79d] closing
2007-05-08 15:43:45,756[Timer-2] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 969 ms
2007-05-08 15:43:45,756[Timer-2] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator failed to ping via SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557]
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.ConnectionValidator.doCheckConnection(ConnectionValidator.java:126)
at org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:195)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 6 more
2007-05-08 15:43:45,771[Timer-2] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557], pingPeriod=2000 ms]'s connections is invalid
2007-05-08 15:43:45,771[Timer-2] DEBUG org.jboss.remoting.InvokerRegistry - removed SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] from registry
2007-05-08 15:43:45,771[Timer-2] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557] disconnecting ...
2007-05-08 15:43:45,771[Timer-2] DEBUG org.jboss.remoting.transport.socket.SocketWrapper - ClientSocketWrapper[Socket[addr=/159.125.194.87,port=4557,localport=2997].ef83d3] closing
2007-05-08 15:43:45,771[Timer-2] DEBUG org.jboss.remoting.ConnectionValidator - ConnectionValidator[SocketClientInvoker[1be4777, bisocket://159.125.194.87:4557], pingPeriod=2000 ms] stopped, returning true
2007-05-08 15:43:50,194[Timer-0] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 922 ms
2007-05-08 15:43:50,194[Timer-0] DEBUG org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.LeasePinger.sendClientPing(LeasePinger.java:283)
at org.jboss.remoting.LeasePinger.access$000(LeasePinger.java:20)
at org.jboss.remoting.LeasePinger$LeaseTimerTask.run(LeasePinger.java:315)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 7 more
2007-05-08 15:43:50,194[Timer-0] WARN org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
2007-05-08 15:43:54,428[Timer-1] WARN org.jboss.remoting.transport.bisocket.BisocketServerInvoker - org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask@76db09: detected failure on control connection Thread[control: Socket[addr=/159.125.194.87,port=2837,localport=2998],5,]: requesting new control connection
2007-05-08 15:43:54,444[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - getting secondary locator
2007-05-08 15:43:55,225[Timer-0] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 953 ms
2007-05-08 15:43:55,225[Timer-0] DEBUG org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.LeasePinger.sendClientPing(LeasePinger.java:283)
at org.jboss.remoting.LeasePinger.access$000(LeasePinger.java:20)
at org.jboss.remoting.LeasePinger$LeaseTimerTask.run(LeasePinger.java:315)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 7 more
2007-05-08 15:43:55,225[Timer-0] WARN org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
2007-05-08 15:43:55,428[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 984 ms
2007-05-08 15:43:55,428[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:55,803[Timer-3] WARN org.jboss.remoting.transport.bisocket.BisocketServerInvoker - org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask@19d6af: detected failure on control connection Thread[control: Socket[addr=/159.125.194.87,port=2837,localport=3000],5,]: requesting new control connection
2007-05-08 15:43:55,803[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - getting secondary locator
2007-05-08 15:43:56,631[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1203 ms
2007-05-08 15:43:56,631[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:56,913[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1110 ms
2007-05-08 15:43:56,913[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:57,631[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:43:57,631[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:57,944[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1031 ms
2007-05-08 15:43:57,944[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:58,631[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:43:58,631[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:58,991[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1047 ms
2007-05-08 15:43:58,991[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:43:59,756[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1125 ms
2007-05-08 15:43:59,756[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:00,053[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1062 ms
2007-05-08 15:44:00,053[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:00,256[Timer-0] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 984 ms
2007-05-08 15:44:00,256[Timer-0] DEBUG org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.LeasePinger.sendClientPing(LeasePinger.java:283)
at org.jboss.remoting.LeasePinger.access$000(LeasePinger.java:20)
at org.jboss.remoting.LeasePinger$LeaseTimerTask.run(LeasePinger.java:315)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 7 more
2007-05-08 15:44:00,319[Timer-0] WARN org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
2007-05-08 15:44:00,756[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:44:00,756[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:01,053[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:44:01,053[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:01,975[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1219 ms
2007-05-08 15:44:01,975[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:02,053[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:44:02,053[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:02,960[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 985 ms
2007-05-08 15:44:02,960[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:03,069[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1016 ms
2007-05-08 15:44:03,069[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:03,975[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1015 ms
2007-05-08 15:44:03,975[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:04,069[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:44:04,069[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:04,991[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1016 ms
2007-05-08 15:44:04,991[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:04,991[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] ERROR org.jboss.remoting.transport.bisocket.BisocketServerInvoker - unable to get secondary locator
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.getSecondaryLocator(BisocketClientInvoker.java:426)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker.createControlConnection(BisocketServerInvoker.java:204)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker$1.run(BisocketServerInvoker.java:948)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 5 more
2007-05-08 15:44:05,194[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1125 ms
2007-05-08 15:44:05,272[Timer-0] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1000 ms
2007-05-08 15:44:05,335[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=2998]] ERROR org.jboss.remoting.transport.bisocket.BisocketServerInvoker - Unable to recreate control connection: InvokerLocator [null://159.125.194.87:2837/null]
java.io.IOException: unable to get secondary locator: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker.createControlConnection(BisocketServerInvoker.java:209)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker$1.run(BisocketServerInvoker.java:948)
2007-05-08 15:44:05,335[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:05,335[Timer-0] DEBUG org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.LeasePinger.sendClientPing(LeasePinger.java:283)
at org.jboss.remoting.LeasePinger.access$000(LeasePinger.java:20)
at org.jboss.remoting.LeasePinger$LeaseTimerTask.run(LeasePinger.java:315)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 7 more
2007-05-08 15:44:05,350[Timer-0] WARN org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557](4f3h5e2f-76or01-f1grt1rk-1-f1grt2zf-5)] failed to ping to server: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
2007-05-08 15:44:06,460[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.socket.MicroSocketClientInvoker - SocketClientInvoker[5660d6, bisocket://159.125.194.87:4557] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 1125 ms
2007-05-08 15:44:06,460[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] DEBUG org.jboss.remoting.transport.bisocket.BisocketClientInvoker - unable to get secondary locator: trying again
2007-05-08 15:44:06,460[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] ERROR org.jboss.remoting.transport.bisocket.BisocketServerInvoker - unable to get secondary locator
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:339)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.getSecondaryLocator(BisocketClientInvoker.java:426)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker.createControlConnection(BisocketServerInvoker.java:204)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker$1.run(BisocketServerInvoker.java:948)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:519)
at org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:187)
at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:346)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:796)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:521)
... 5 more
2007-05-08 15:44:06,647[controlConnectionRecreate:control: Socket[addr=/159.125.194.87,port=2837,localport=3000]] ERROR org.jboss.remoting.transport.bisocket.BisocketServerInvoker - Unable to recreate control connection: InvokerLocator [null://159.125.194.87:2837/null]
java.io.IOException: unable to get secondary locator: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.194.87:4557/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=false&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker.createControlConnection(BisocketServerInvoker.java:209)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker$1.run(BisocketServerInvoker.java:948)

[timfox]

This is a remoting bug that was fixed in 2.2.0.sp2.

It will be available as part of 1.2.0.sp2.

[timfox]

http://jira.jboss.com/jira/browse/JBREM-732

[cresny]

Tim,

I am experiencing the same behavior using either jboss-remoting-2.2.0.SP2 or SP3 (JBoss 4.0.5.GA/JBM 1.2.0.SP1). There was also an issue where an MDB container would get starved/disconnected; this was fixed with remoting 2.2.0.SP2. But the remote client problem exemplified by Gurwinder's test above still does exist.

Below is an abbreviated log from the above test (only top-level traces), annotated with my guesswork. As you can see the connection quickly dies off. I have played with the bisocket parameters (check_connection=true, etc., from the jboss-messaging service config) with no luck.

I understand this is largely a remoting issue and should perhaps be added to JBREM-732, except for one thing: if the MessageConsumer loses its connection, can't an Exception be thrown? this would at least allow for a fallback if remoting fails. Otherwise it's just a silent death!

Set up remote consumer (no timeout on receive)

14:18:35,501 DEBUG [SocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] setting timeout to 1000
14:18:35,501 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] constructed
14:18:35,501 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] setting maxPoolSize to 50
14:18:35,501 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
14:18:35,501 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] setting shouldCheckConnection to true
14:18:35,501 DEBUG [SocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] setting timeout to 1000
14:18:35,501 DEBUG [MicroRemoteClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] connecting
14:18:35,501 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] added new pool ([]) as ServerAddress[159.125.154.138:4757, NO enableTcpNoDelay timeout 1000 ms]
14:18:35,501 DEBUG [MicroRemoteClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] connected
14:18:35,501 DEBUG [ConnectionValidator] ConnectionValidator[SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757], pingPeriod=2000 ms] started
14:18:35,501 DEBUG [MessageIdGeneratorFactory] checked out MessageIdGenerator for 3, reference count is 1
14:18:35,516 DEBUG [ClusteringAspect] ClusteringAspect[ClusteredConnectionFactoryDelegate[SIDs={3}]] got local connection delegate ConnectionDelegate[32598031, ID=3, SID=3]
14:18:35,516 DEBUG [ConsolidatedRemotingConnectionListener] ConnectionState[3].ConsolidatedListener adding delegate listener ConnectionFailureListener[FailoverCommandCenter[ConnectionState[3]]]
14:18:35,516 DEBUG [ClusteringAspect] ClusteringAspect[ClusteredConnectionFactoryDelegate[SIDs={3}]] installed failure listener on ConnectionDelegate[32598031, ID=3, SID=3]
14:18:36,126 DEBUG [JBossSession] attempting to create consumer for destination:JBossQueue[testQueue]
listening

Bring down messaging server. Remoting determines it is orphaned and connection is invalid.


14:19:17,501 DEBUG [SocketWrapper] ClientSocketWrapper[Socket[addr=/159.125.154.138,port=4757,localport=3687].da3772] closing
14:19:18,501 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] got Exception java.net.SocketTimeoutException: connect timed out, creation attempt took 1000 ms
14:19:18,501 DEBUG [ConnectionValidator] ConnectionValidator failed to ping via SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757]
org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
Caused by: java.net.SocketTimeoutException: connect timed out
14:19:18,501 DEBUG [ConnectionValidator] ConnectionValidator[SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757], pingPeriod=2000 ms]'s connections is invalid


Attempt to deregister/clean up remote connections(?)

14:19:18,517 DEBUG [InvokerRegistry] removed SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] from registry
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] disconnecting ...
14:19:18,517 DEBUG [ConsolidatedRemotingConnectionListener] ConnectionState[3].ConsolidatedListener forwarding remoting failure "java.lang.Exception: Could not connect to server!" to ConnectionFailureListener[FailoverCommandCenter[ConnectionState[3]]]
14:19:18,517 DEBUG [ConnectionFailureListener] ConnectionFailureListener[FailoverCommandCenter[ConnectionState[3]]] is being notified of connection failure: java.lang.Exception: Could not connect to server!
14:19:18,517 DEBUG [SocketWrapper] ClientSocketWrapper[Socket[addr=/159.125.154.138,port=4757,localport=3685].738d08] closing
14:19:18,517 DEBUG [FailoverCommandCenter] failure detected by ConnectionFailureListener[FailoverCommandCenter[ConnectionState[3]]]
14:19:18,517 DEBUG [ConnectionValidator] ConnectionValidator[SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757], pingPeriod=2000 ms] stopped, returning true

14:19:18,517 DEBUG [LeasePinger] LeasePinger[SocketClientInvoker[52c6b4, bisocket://159.125.154.138:4757](4f3h4a3u-e9roa5-f1i47q1j-1-f1i47qrk-5)] setting disconnect timeout to: 0
14:19:18,517 DEBUG [InvokerRegistry] removed SocketClientInvoker[52c6b4, bisocket://159.125.154.138:4757] from registry
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[52c6b4, bisocket://159.125.154.138:4757] disconnecting ...
14:19:18,517 DEBUG [JMSRemotingConnection] JMSRemotingConnection[bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] failed to cleanly remove callback manager from the client
java.lang.Exception: Can not remove callback listener as remoting client is not connected to server.
at org.jboss.remoting.Client.removeListener(Client.java:1090)


Attempt to reestablish?

14:19:18,517 DEBUG [FailoverCommandCenter] FailoverCommandCenter[ConnectionState[3]] starting client-side failover
14:19:18,517 DEBUG [ClusteringAspect] ClusteringAspect[ClusteredConnectionFactoryDelegate[SIDs={3}]] has chosen ConnectionFactoryDelegate[1, SID=3] as target, 1 connection attempts
14:19:18,517 DEBUG [JMSRemotingConnection] JMSRemotingConnection[bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] created
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] setting maxPoolSize to 50
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] setting shouldCheckConnection to true
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] constructed
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] setting maxPoolSize to 50
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] setting client socket wrapper class name to org.jboss.jms.client.remoting.ClientSocketWrapper
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] setting shouldCheckConnection to true
14:19:18,517 DEBUG [MicroRemoteClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] connecting
14:19:18,517 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] added new pool ([]) as ServerAddress[159.125.154.138:4757, NO enableTcpNoDelay timeout 0 ms]
14:19:18,517 DEBUG [MicroRemoteClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] connected
14:19:19,439 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[174a6e2, bisocket://159.125.154.138:4757] got Exception java.net.ConnectException: Connection refused: connect, creation attempt took 922 ms
14:19:19,439 DEBUG [JMSRemotingConnection] JMSRemotingConnection[bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat] closing
14:19:19,439 ERROR [DelegateSupport] Failed
java.lang.RuntimeException: Error setting up client lease upon performing connect.
Caused by: java.lang.Exception: Error setting up client lease
at org.jboss.remoting.MicroRemoteClientInvoker.establishLease(MicroRemoteClientInvoker.java:405)
Caused by: org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
14:19:19,439 ERROR [FailoverCommandCenter] Failover failed
org.jboss.jms.util.MessagingJMSException: Failed to invoke
at org.jboss.jms.client.delegate.DelegateSupport.handleThrowable(DelegateSupport.java:225)
Caused by: java.lang.RuntimeException: Error setting up client lease upon performing connect.
at org.jboss.remoting.Client.connect(Client.java:1445)
Caused by: java.lang.Exception: Error setting up client lease
at org.jboss.remoting.MicroRemoteClientInvoker.establishLease(MicroRemoteClientInvoker.java:405)
Caused by: org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
14:19:19,439 DEBUG [FailoverCommandCenter] FailoverCommandCenter[ConnectionState[3]] aborted failover
14:19:19,439 ERROR [ConnectionFailureListener] Caught exception in handling failure
org.jboss.jms.util.MessagingJMSException: Failed to invoke
at org.jboss.jms.client.delegate.DelegateSupport.handleThrowable(DelegateSupport.java:225)
Caused by: java.lang.RuntimeException: Error setting up client lease upon performing connect.
at org.jboss.remoting.Client.connect(Client.java:1445)
Caused by: java.lang.Exception: Error setting up client lease
at org.jboss.remoting.MicroRemoteClientInvoker.establishLease(MicroRemoteClientInvoker.java:405)
Caused by: org.jboss.remoting.CannotConnectException: Can not get connection to server. Problem establishing socket connection for InvokerLocator [bisocket://159.125.154.138:4757/?NumberOfCallRetries=2&clientMaxPoolSize=50&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&leasePeriod=10000&leasing=true&marshaller=org.jboss.jms.server.remoting.JMSWireFormat&numberOfRetries=1&serializationtype=jms&socket.check_connection=true&unmarshaller=org.jboss.jms.server.remoting.JMSWireFormat]
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:525)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
14:19:29,939 WARN [BisocketServerInvoker] org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask@869113: detected failure on control connection Thread[control: Socket[addr=/159.125.154.138,port=3948,localport=3686],5,]: requesting new control connection
14:19:29,939 DEBUG [BisocketServerInvoker] Unable to retrieve client invoker: must have disconnected
14:19:29,939 DEBUG [BisocketServerInvoker] Unable to recreate control connection: InvokerLocator [null://159.125.154.138:3948/null]
org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ClientUnavailableException
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker.createControlConnection(BisocketServerInvoker.java:196)
at org.jboss.remoting.transport.bisocket.BisocketServerInvoker$1.run(BisocketServerInvoker.java:948)

failed, disconnects for good. (messaging listener DOES NOT get exception)

14:19:36,127 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] disconnecting ...
14:19:36,127 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[137d4a4, bisocket://159.125.154.138:4757] disconnecting ...
14:19:36,127 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[52c6b4, bisocket://159.125.154.138:4757] disconnecting ...
14:19:36,127 DEBUG [MicroSocketClientInvoker] SocketClientInvoker[52c6b4, bisocket://159.125.154.138:4757] disconnecting ...

[timfox]

If you add a JIRA task, describe how to replicate it etc, someone will take a look.

[timfox]

Are you running a cluster or standalone?

[timfox]

Ok, i have added a JIRA task http://jira.jboss.com/jira/browse/JBMESSAGING-959

[timfox]

In the MDB case, are you consuming messages in using MDBs in one app server from a messaging server in a different app server instance, or is it all colocated?

[cresny]

"timfox" wrote:
In the MDB case, are you consuming messages in using MDBs in one app server from a messaging server in a different app server instance, or is it all colocated?

JBoss Messaging and the server hosting the mdbs are two different machines. The mdbs are depoyed scoped, using the JCA resource adapter. Also, we have nothing else colocated on the JBoss Messaging instance.

[timfox]

If you have one machine hosting the MDBs and another hosting JBM, then it looks like clustering is not useful to you.

Are you running clustered or non clustered? To find this out, look in your jboss-messaging.sar directory.

There will be a file there called something-persistence-service.xml. If you're file starts with "clustered" then you are running clustered.

[cresny]

It was clustered, changed to non-clustered ds.

The behavior is different , but still not correct. It now repeatedly recreates a control connection, trying various local ports.

Remote Consumer still does not pick up messages, still no Exception thrown, so still hangs on receive.

repeats (with different local ports):

13:53:55,959 WARN [BisocketServerInvoker] org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask@1c09624: detected failure on control connection Thread[control: Socket[addr=/159.125.154.138,port=3685,localport=3907],5,main]: requesting new control connection
13:53:55,959 DEBUG [BisocketClientInvoker] getting secondary locator
13:53:55,959 DEBUG [BisocketClientInvoker] secondary locator: InvokerLocator [null://159.125.154.138:3685/null]
13:53:55,959 DEBUG [BisocketServerInvoker] creating control connection: InvokerLocator [null://159.125.154.138:3685/null]
13:53:55,974 DEBUG [BisocketServerInvoker] created control connection: Socket[addr=/159.125.154.138,port=3685,localport=3913]

finally it, too, errors out:

13:56:56,014 WARN [BisocketServerInvoker] Control connection 4f3h4a3u-oowm7j-f1qnw10s-1-f1qnw1qt-7 has been recreated 10 times.
13:56:56,014 WARN [BisocketServerInvoker] Assuming it is a connection to an old server, and will not restart

Regarding clustering, I'm hoping you can clear something up for me. We planned to deploy JBM in its own cluster, apart from an application cluster, mostly for failover purposes.
All queues would be distributed across the JBM cluster, and remote lookups would be using HAJNDI.

However, your above comments indicate deploying JBM instances and Application instances in a single cluster. Is this the recommended configuration?

BTW, thanks for your time and effort on this, it's much appreciated.

[timfox]

A couple more questions:

Are you deploying clustered or non clustered destinations (look for the clustered attribute on the destination mbean config)?

Are you using the JCA JMS resource asaptor (the one at java:/JmsXA)?

If you are using the JCA resource adaptor, what does your jms-ds.xml look like?

[cresny]

The destination is not clustered.

As for the resource adapter, no, the remote client that this topic is about (see 1st message) is using a remote lookup for connection factory and queue.
If you mean, does the JBM instance use the resource adapter, then yes it does - the one in the exploded jboss-messaging.sar configured from the JBM distribution ant script.

I'm hoping I didn't confuse matters by mentioning mdbs. I only did so in contrast, because remote reconnect *is working* for the mdb container.
It's just our remote clients that are hanging when the JBM instance is restarted.

[timfox]

Ok, I thought you were having problems with MDBs.

Can you explain your setup in more detail and what is going wrong?

[cresny]

setup: JBM 1.2.0.SP1 patched with jboss-remoting 2.2.0.SP3

1. Remote, standalone client connects to non-clustered JBM instance.

2. Client creates session, consumer on non-clustered queue destination, blocks on receive().

3. JBM instance is restarted.

4. jboss-remoting loses connection to server. No Exception is thrown.

5. client interminably remains blocked on receive.

Any further information, including sample code (post #1), is detailed in this topic. There really is nothing more I think I can add, but let me know.