[jboss-user] [Remoting] - JMS receiving connection dropped (ConnectionValidator), clie

[tomeicher]

Hello,

we have an JBoss ESB 4.5.ga (jboss.org)
(also tried upgrading the remoting.jar to 2.5.1, to no effect)

and a standalone Application to act as a JMS client, using
jboss messaging client 1.1
jbos remoting 2.5.1 
jboss aop jdk5 1.5.5ga
(other libraries copied over from ESB as needed)
to connect to the central ESB (same instance in all 5 cases I
explain below)

Now, starting up the client, everything looks fine, but after some time
(sometimes after a few minutes, usually about 10min), the client seems 
to loose it's (receiving) connection. Worse, the client doesn't notice
this, and continues to "listen" for messages, that queue up at the ESB, but
are no longer received at the client.

Loss of connection:


  | 2009-05-15 10:46:08,956 DEBUG Thread-54 org.jboss.remoting.ConnectionValidator - Thread[Thread-54,5,main] calling ConnectionState[zx3-zko0nquf-1-jmauqmuf-1f7h3-w3l3hs4].ConsolidatedListener.handleConnectionException()
  | 2009-05-15 10:46:08,966 DEBUG Timer-4 org.jboss.remoting.ConnectionValidator - ConnectionValidator[d166b5:SocketClientInvoker[8a224d, bisocket://gerappxx.xxxxxxxx.xxxx.xxxxxxx.com:20098], pingPeriod=2000 ms] stopped, returning true
  | 2009-05-15 10:46:08,966 DEBUG Timer-4 org.jboss.remoting.ConnectionValidator - org.jboss.remoting.ConnectionValidator$WaitOnConnectionCheckTimerTask at ba5cbf detected connection failure: stopping LeasePinger
  | 2009-05-15 10:46:08,970 DEBUG Timer-4 org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[70241a, bisocket://gerappxx.xxxxxxxx.xxxx.xxxxxxx.com:20098](3j001-dhemnd-fuqn2dqu-1-fuqn2fi9-6)] setting disconnect timeout to: -1
  | 2009-05-15 10:46:08,979 DEBUG Timer-4 org.jboss.remoting.LeasePinger - LeasePinger[SocketClientInvoker[70241a, bisocket://gerappxx.xxxxxxxx.xxxx.xxxxxxr.com:20098](3j001-dhemnd-fuqn2dqu-1-fuqn2fi9-6)]: disconnectTimeout: -1
  | 2009-05-15 10:46:08,982 DEBUG Timer-4 org.jboss.remoting.ConnectionValidator - ConnectionValidator[d166b5:SocketClientInvoker[8a224d, bisocket://gerappxx.xxxxxxxx.xxxx.xxxxxxr.com:20098], pingPeriod=2000 ms] shut down lease pinger
  | 2009-05-15 10:46:08,982 DEBUG WorkerThread#0[172.17.129.140:20457] org.jboss.jms.server.remoting.ServerSocketWrapper - wrote CLOSING byte
  | 2009-05-15 10:46:08,982 DEBUG WorkerThread#0[172.17.129.140:20457] org.jboss.remoting.transport.socket.ServerThread - WorkerThread#0[172.17.129.140:20457] closed socketWrapper: ServerSocketWrapper[Socket[addr=gerappxx.xxxxxxxx.xxxx.xxxxxxx.xxx/172.17.129.140,port=20457,localport=49313].3949e7]
  | 2009-05-15 10:46:09,770 DEBUG Timer-3 org.jboss.remoting.ConnectionValidator - ConnectionValidator failed to ping via SocketClientInvoker[8a224d, bisocket://gerappxx.xxxxxxxx.xxxx.xxxxxxx.com:20098]
  | java.lang.Exception
  |         at org.jboss.remoting.ConnectionValidator.doCheckConnectionWithLease(ConnectionValidator.java:654)
  |         at org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:334)
  |         at java.util.TimerThread.mainLoop(Timer.java:512)
  |         at java.util.TimerThread.run(Timer.java:462)
  | 2009-05-15 10:46:30,829 DEBUG JmsCommunicationServiceImpl-Receiver com.xxxxxxx.xx.xxxxxxx.xxx.JmsCommunicationServiceImpl - no message during timeout period. another turn...
  | 

And the listening client works like this:


  | 	InitialContext ctx = new InitialContext(connectionProperties);
  | 	queueOut = (Queue) ctx.lookup(queueNameOut);
  | 	queueIn = (Queue) ctx.lookup(queueNameIn);
  | 
  | 	QueueConnectionFactory qcf = (QueueConnectionFactory) ctx.lookup(connectionFactory);
  | 	QueueConnection qc = qcf.createQueueConnection();
  | 	qc.setClientID(Prefs.get("serverId"));
  | 	ctx.close();
  | 	qc.start();
  | 	...
  | 	while (!terminate && queueConnection!=null)
  | 	{
  | 		try {
  | 			QueueSession qsession = queueConnection.createQueueSession(false, javax.jms.Session.AUTO_ACKNOWLEDGE);
  | 			QueueReceiver qreceiver = qsession.createReceiver(queueIn);
  | 			Message msg = null;
  | 			try {
  | 				msg = qreceiver.receive(60*1000);
  | 			} catch (JMSException e) {
  | 				log.error("waiting for message", e);
  | 			}
  | 
  | 			if (msg==null)
  | 			{
  | 				log.debug("no message during timeout period. another turn...");
  | 			}
  | 			else
  | 			{
  | 				log.info("received message #"+msg.getJMSMessageID());
  | 				...
  | 			}
  | 
  | 			qreceiver.close();
  | 			qsession.close();
  | 		}
  | 		catch (Exception e)
  | 		{
  | 			log.error("trying to receive message(s)", e);
  | 			log.info("trying to recover - re-initing JMS, then retrying receive");
  | 			...
  | 		}
  | 

So the qreceiver.receive() is never notified, interrupted or similar with the
connection failure, but continues it's "futile receive". After the timeout, the
next call to qreceiver.receive() also "works" - but messages are no longer received.

So far, we could reproduce this problem on a Mac OS 10.5.6/Java 1.6.07 (final) and a
Mac OS 10.4.11/Java 1.6.0-dp-b88-34 (developer preview), 
but NOT on the two other developer machines running Vista Ultimate SP1/Java 1.6.0.13-b03
and openSuSE 11.1/Java 1.6.0.13, all running identical code.

(But we're not yet convinced that it's an Apple specific problem... Lot's of you
JBoss guys also have Macs, so this surely wouldn't have been missed ;-)

I can reproduce, so if you want specific logging enabled, have suggestions for
config params ... go ahead.

Any input and feedback is greatly appreciated.

Thanks,
Tom.






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

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