[jboss-user] [JBoss Messaging] - Re: Message receiver connot reconnect after the messaging se

Wed May 9 15:00:24 EDT 2007

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 at 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 ...

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4044450#4044450

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4044450