JMS Framework Stops on changing System Time

[hskiran]

Hello All,

My Application uses JMS to execute scheduled Jobs, and these jobs run every minute.

But when JBOSS is running, if I change the System time, I get following exception from JMS framework and the whole JMS framewrok stops working. (org.jboss.mq.SpyJMSException: Cannot ping the JMS server; - nested throwable: (java.io.IOException: Client is not connected)
)

I tried to set the Exception listener, but did not work out. Does anybody has an idea what is the problem?

006-12-13 18:55:57,732 TRACE [org.jboss.mq.il.uil2.UILServerIL] Connecting with addr=10.0.10.52, port=8093, localAddr=null, localPort=0, socketFactory=javax.net.DefaultSocketFactory@1d60412, enableTcpNoDelay=true, bufferSize=2048, chunkSize=1000000
2006-12-13 18:55:57,732 TRACE [org.jboss.mq.il.uil2.UILServerIL] Begin connect loop, maxRetries=10, delay=0
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.il.uil2.SocketManager] start called
java.lang.Exception: Start stack trace
at org.jboss.mq.il.uil2.SocketManager.start(SocketManager.java:96)
at org.jboss.mq.il.uil2.UILServerIL.createConnection(UILServerIL.java:666)
at org.jboss.mq.il.uil2.UILServerIL.getSocketMgr(UILServerIL.java:532)
at org.jboss.mq.il.uil2.UILServerIL.authenticate(UILServerIL.java:334)
at org.jboss.mq.Connection.authenticate(Connection.java:1114)
at org.jboss.mq.Connection.(Connection.java:267)
at org.jboss.mq.Connection.(Connection.java:338)
at org.jboss.mq.SpyConnection.(SpyConnection.java:68)
at org.jboss.mq.SpyConnectionFactory.createConnection(SpyConnectionFactory.java:87)
at org.jboss.mq.SpyConnectionFactory.createQueueConnection(SpyConnectionFactory.java:124)
at de.coconet.job.AbstractJob.executeWait(AbstractJob.java:1310)
at de.coconet.mwcustody.task.ExecuteJob.executeJob(ExecuteJob.java:241)
at de.coconet.job.TimerEntry.run(TimerEntry.java:91)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.il.uil2.UILServerILService] Accepted connection: Socket[addr=/10.0.10.52,port=3806,localport=8093]
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : getThreadGroup
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : getThreadGroup
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.il.uil2.SocketManager] start called
java.lang.Exception: Start stack trace
at org.jboss.mq.il.uil2.SocketManager.start(SocketManager.java:96)
at org.jboss.mq.il.uil2.UILServerILService.run(UILServerILService.java:134)
at java.lang.Thread.run(Thread.java:595)
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.CheckUserMsg29361740[msgType: m_authenticate, msgID: -2147483440, error: null]
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.Connection] PING 1166016357742 Connection@29140661[token=ConnectionToken:ID:7/810ca89fb0609798e062b52c9eef75dc rcvstate=STARTED]
2006-12-13 18:55:57,742 TRACE [org.jboss.mq.Connection] Notified of failure reason=Unexpected ping failure Connection@29140661[token=ConnectionToken:ID:7/810ca89fb0609798e062b52c9eef75dc rcvstate=STARTED]
org.jboss.mq.SpyJMSException: Cannot ping the JMS server; - nested throwable: (java.io.IOException: Client is not connected)
at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
at org.jboss.mq.SpyJMSException.rethrowAsJMSException(SpyJMSException.java:51)
at org.jboss.mq.Connection.pingServer(Connection.java:887)
at org.jboss.mq.Connection$PingTask.run(Connection.java:1327)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.io.IOException: Client is not connected
at org.jboss.mq.il.uil2.SocketManager.internalSendMessage(SocketManager.java:238)
at org.jboss.mq.il.uil2.SocketManager.sendReply(SocketManager.java:224)
at org.jboss.mq.il.uil2.UILServerIL.ping(UILServerIL.java:462)
at org.jboss.mq.Connection.pingServer(Connection.java:883)
... 3 more

[byorn]

Please explain more on how your jobs are scheduled. ??? How can jms schedule a job ? Isnt it done my Timer or Quartz ???

[hskiran]

Hi Byorn,

Thank you for the response.

We write our own logic using Timer to schedule the JOBS. Once the Jobs are activated it is handed over to JMS framework to execute these jobs.
Here is a code snippet.

qConnection = qConnectionFactory.createQueueConnection();
q=Session = qConnection.createQueueSession(false, Session.AUTO_ACKNOWLEDGE);
qSender = qSession.createSender(q);
MapMessage msg = qSession.createMapMessage();
//set some data of the JOBS to message
qSender.send(msg);

I hope I have answered your question, if not so pls ask.

Regards,
Shashi

[philc]

I have the same issue on JBoss 4.0.3SP1. Changing the system time crashed my Topic Subscriber. Unfortunately I don't have a stack trace, but only a print out of the JMSException.toString()

 org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.io.EOFException)

I could try to reproduce this on a test system with a stack trace if anybody needs it.

[njain15]

Not sure if someone still looking for the answer. We had similar issue and looking at the JBoss code, figured out following -

Whenever a JMS connection is created in JBoss, JBoss schedules a thread that checks for the validity of the connection. The validity criteria is such that JBoss expects another message from the connection's client with in 2 min (by default, it might be configurable) since last message is received. If no message is received from client then connection is considered stale and closed.

The exception in your case is because of this behavior.

Since a JMS client application may not send a message every two minutes, the JMS implementation sends a PingMessage to the connection every 60 sec to keep it alive.

To schedule the PING for every 60 sec, JBoss uses the ClockDeamon class from 'EDU', that provides a feature to schedule a task periodically. The application works as expected if you increase the system time. If system time is decreased, it fails to send to PING message every 60 sec and hence connection times out after 2 min.

Look at the implementation of 'nextTask' method in 'ClockDeamon' class for details.

One of the possible approach to fix the issue is to register a javax.jms.ExceptionListener with the JMS connection. This listener is notified whenever JMS system encounters any error with the connection. During call back, you should recreate the connection and all the associated JMS objects.

Here is snippet of a TextMDB (will not compile as it is, removed unnecessary code to reduce the text) that uses the above mentioned approach

public class TextMDB implements MessageDrivenBean, MessageListener, ExceptionListener
{

private MessageDrivenContext ctx = null;
private QueueConnection conn;
private QueueSession session;

public void ejbCreate() {
setupPTP();
}

public void onMessage(Message msg) {
TextMessage tm = (TextMessage) msg;
String text = tm.getText() + "processed by: " + hashCode();
Queue dest = (Queue) msg.getJMSReplyTo();
sendReply(text, dest);
}

private void setupPTP() throws JMSException, NamingException {
InitialContext iniCtx = new InitialContext();
Object tmp = iniCtx.lookup("java:comp/env/jms/QCF");
QueueConnectionFactory qcf = (QueueConnectionFactory) tmp;
conn = qcf.createQueueConnection();
conn.setExceptionListener(this);
session = conn.createQueueSession(false,
QueueSession.AUTO_ACKNOWLEDGE);
conn.start();
}

private void sendReply(String text, Queue dest) throws JMSException {
QueueSender sender = session.createSender(dest);
TextMessage tm = session.createTextMessage(text);
sender.send(tm);
sender.close();
}

public void onException(JMSException jMSException) {
setupPTP();
}

}

Hope this helps

[adrian.brock]

"njain15" wrote:

One of the possible approach to fix the issue is to register a javax.jms.ExceptionListener with the JMS connection. This listener is notified whenever JMS system encounters any error with the connection. During call back, you should recreate the connection and all the associated JMS objects.

You should always do this (except for trivial uses of JMS).

The comments about ping are irrelevant. The reason for the IOE is at the
operating system level (and the read timeout).
Some operating systems will say that the read timed out and close the tcp/ip socket
when you change the clock because they use absolute time rather than relative time.

[hskiran]

Hi njain15,

I am still interested in this topic.
I will try your solution and let you know the result.

Thanks for the info.

Bye
hskiran