Three problems maybe related maybe not - Durable Topic Subsc
mcaughey Jul 29, 2005 5:10 AMI have a Durable Subscription to a topic. Every now and then I notice the JBoss Server throws:
[SocketManager] Failed to handle: org.jboss.mq.il.uil2.msgs.AcknowledgementRequest from the
Here's the full Trace:
04:32:32,097 ERROR [SocketManager] Failed to handle: org.jboss.mq.il.uil2.msgs.AcknowledgementRequestMsg8251436[msgType: m_acknowledge, msgID: 232, error: null] java.lang.NullPointerException at org.jboss.mq.server.JMSTopic.acknowledge(JMSTopic.java:291) at org.jboss.mq.server.ClientConsumer.acknowledge(ClientConsumer.java:328) at org.jboss.mq.server.JMSDestinationManager.acknowledge(JMSDestinationManager.java:519) at org.jboss.mq.server.JMSDestinationManager.acknowledge(JMSDestinationManager.java:503) at org.jboss.mq.server.JMSServerInterceptorSupport.acknowledge(JMSServerInterceptorSupport.java:198) at org.jboss.mq.server.JMSServerInterceptorSupport.acknowledge(JMSServerInterceptorSupport.java:198) at org.jboss.mq.server.TracingInterceptor.acknowledge(TracingInterceptor.java:481) at org.jboss.mq.server.JMSServerInvoker.acknowledge(JMSServerInvoker.java:198) at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:87) at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:369) at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377) at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:743) at java.lang.Thread.run(Thread.java:595)
I'm running JBoss 4.0.2. My topic is still presisting to the HyperSonic DB. I notice that the message associated with this problem never makes it to my client nor nor does the one after it. I can tell this becuase the time stamp of when I sent it and when I recieve it matches on all the ones recieved. I do a System out just before i sent it and just after I recv it. There is only one subscriber and its on the same computer as JBoss. The client is running in a seperate JVM.
04:32:26,706 INFO [GetInformationJDBCTask] Publishing - 1122625946706 04:32:32,050 INFO [GetInformationJDBCTask] Publishing - 1122625952050 ERROR Occurred Here 04:32:37,113 INFO [GetInformationJDBCTask] Publishing - 1122625957113 04:32:42,128 INFO [GetInformationJDBCTask] Publishing - 1122625962128 04:32:47,175 INFO [GetInformationJDBCTask] Publishing - 1122625967175 04:32:52,191 INFO [GetInformationJDBCTask] Publishing - 1122625972191 04:32:57,238 INFO [GetInformationJDBCTask] Publishing - 1122625977238 Here are the time stamps of the recv'd 1122625946738 - 0 1,1, 1122625962175 - 1 1,1, 1122625967175 - 2 1,1, 1122625972222 - 3 1,1, 1122625977253 - 4 1,1,
You can see that two messages were never recieved. How can this happen with a durable topic?
I do have a quick time out of 50 ms. I need it to check the topic and bug out if nothing is there, I return almost instantly. I have to do this becuase of how a plugin (Moka) works with Director, so every second we check again. In my test application I tried two things one is to simply return imediately:
for (int i = 0; i < 5; i++) { msg = m.retrieveInfo(); if(msg == null){ i--; }else{ System.out.println(" "+ System.currentTimeMillis()+" - " + i + " " + msg); } }
That produces the condition above. I mention this becuase I don't know if the short timeout is the cause the problem or not. I did see it once with a 5000 ms time out. I also mention this becuase I'm seeing another weird thing. If I add a sleep each time the msg comes back null like this:
for (int i = 0; i < 5; i++) { msg = m.retrieveInfo(); if(msg == null){ i--; try { Thread.sleep(750); } catch (InterruptedException e) { } }else{ System.out.println(" "+ System.currentTimeMillis()+" - " + i + " " + msg); } }
I can go a minute with no response from the topic, but all the while the publisher on the server is publishing a new message every 5 seconds. Here's how i'm establishing my Topic,
public void init() throws JMSException, NamingException { Properties props = new Properties(); props.setProperty(Context.INITIAL_CONTEXT_FACTORY, "org.jnp.interfaces.NamingContextFactory"); props.setProperty(Context.URL_PKG_PREFIXES, "org.jboss.naming:org.jnp.interfaces"); props.setProperty(Context.PROVIDER_URL, serverUrl); InitialContext ctx = new InitialContext(props); Object o = ctx.lookup("ConnectionFactory"); TopicConnectionFactory tcf = (TopicConnectionFactory) o; conn = tcf.createTopicConnection(username, password); // conn = tcf.createTopicConnection(); topic = (Topic) ctx.lookup("topic/lobbyTopic"); session = conn.createTopicSession(false, TopicSession.AUTO_ACKNOWLEDGE); conn.start(); sub = session.createDurableSubscriber(topic, username, "Type = " + type, true); }
Here's my recv method:
public String recv() throws JMSException, NamingException { TextMessage tm = null; tm = (TextMessage) sub.receive(50); return (tm==null)?null:tm.getText(); }
So you can see i have the Durable Sbscription the whole time. This test by the way is being run from a standalone commandline console app. It is not yet being run in MOKA.
One last issue. I'm now seeing this error in the log file and it is occurring many times in a row:
04:48:03,265 WARN [Connection] Connection failure, use javax.jms.Connection.setExceptionListener() to handle this error and reconnect org.jboss.mq.SpyJMSException: No pong received; - nested throwable: (java.io.IOException: ping timeout.) at org.jboss.mq.Connection$PingTask.run(Connection.java:1323) 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: ping timeout.
What is this? I do have 5 durable connections that were created and never unsuscribed. Is the problem related to this? If so that easy to fix. My code has been modified to unscribe the the user. If it is related however then how do you configure JBossMQ to simply drop a client after a period of time, like and expiration time? I would think you could remove all associated messages with that expiration.
Thanks,
michael