6 Replies Latest reply on Oct 22, 2009 8:51 AM by tomeicher

    JMS receiving connection dropped (ConnectionValidator), clie

    tomeicher
    tomeicher May 15, 2009 10:47 AM

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






      • 7707 Views
      • Tags: