6 Replies Latest reply on Oct 2, 2009 5:18 PM by b.eckenfels

Weird behavior with ping timeouts

smithmb Sep 15, 2006 11:46 AM

Hello all,

I was wondering if anyone has seen the following behavior before, and if anyone knows a solution for it. We appear to have messages that aren't being delivered. The following is a snip of our logs:

2006-09-15 11:27:59,543 WARN [org.jboss.mq.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:1277)
 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.
 ... 3 more
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_ping, msgID: 64
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg1890854[msgType: m_ping, msgID: 64, error: null]
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1158334085647
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg9602832[msgType: m_pong, msgID: -2147466927, error: null]
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg9602832[msgType: m_pong, msgID: -2147466927, error: null]
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg9602832[msgType: m_pong, msgID: -2147466927, error: null]
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping
2006-09-15 11:28:06,308 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
2006-09-15 11:28:11,121 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
2006-09-15 11:28:11,121 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping
2006-09-15 11:28:11,121 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1158334092214
2006-09-15 11:28:11,121 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping
2006-09-15 11:28:11,121 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
... traced ping message repeats ...
2006-09-15 11:28:46,120 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
2006-09-15 11:28:46,120 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping
2006-09-15 11:28:46,120 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1158334126064
2006-09-15 11:28:46,120 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping
2006-09-15 11:28:46,120 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
2006-09-15 11:28:59,557 WARN [org.jboss.mq.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:1277)
 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.
 ... 3 more
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_ping, msgID: 65
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg18189100[msgType: m_ping, msgID: 65, error: null]
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1158334145653
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg8764440[msgType: m_pong, msgID: -2147466921, error: null]
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg8764440[msgType: m_pong, msgID: -2147466921, error: null]
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg8764440[msgType: m_pong, msgID: -2147466921, error: null]
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping
2006-09-15 11:29:06,323 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
2006-09-15 11:29:11,135 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
2006-09-15 11:29:11,135 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping
2006-09-15 11:29:11,135 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1158334152238
2006-09-15 11:29:11,135 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping
2006-09-15 11:29:11,135 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
.. more ping messages...

We have 3 different database connections open, in addition to the JMS backend which is still the default Hypersonic one. It appears some of the logged pings are for those. I'm tracing with the following (from READTHISFIRST) but I'm not sure what other diagnostic information to aquire.

<category name="org.jboss.mq">
 <priority value="TRACE" class="org.jboss.logging.XLevel"/>
</category>

My uil2-service.xml contains

<!-- The ping period in millis -->
 <attribute name="PingPeriod">60000</attribute>

, so I shouldn't really be having this big of a problem with ping timeouts. After all, the JMS backend is a local database on the same machine, with mostly the default JBoss installer-configured settings.

Can anyone suggest the problem or even other ways to analyze it? Thank you.

1. Re: Weird behavior with ping timeouts

jaikiran Sep 21, 2006 11:10 AM (in response to smithmb)

Have a look at:
http://wiki.jboss.org/wiki/Wiki.jsp?page=IGetIOExceptionPingTimeoutHowDoIFixIt
Actions
2. Re: Weird behavior with ping timeouts

smithmb Sep 21, 2006 12:54 PM (in response to smithmb)

Thank you for the reply. Unfortunately, I've already seen that page. This is what it suggested:

I'm inside the application server, how do I install the exception listener?

* You don't need to for an MDB, JBoss does it for you.
* For anything else, you should be using the JMS resource adapter which also does it for you.

This project already does these. So basically, if in the application server, "This shouldn't happen" is the answer -- which doesn't really help! I still don't understand how the Hypersonic JMS backend would get a ping timeout at all!
Actions
3. Re: Weird behavior with ping timeouts

lgirault Oct 11, 2006 1:33 PM (in response to smithmb)

Hello,

did you manage to fix your problem ?
I am exactly in the same situation: "No pong received"
If you get any chance fixing this issue please let me know.

Thank you
Actions
4. Re: Weird behavior with ping timeouts

smithmb Oct 11, 2006 1:36 PM (in response to smithmb)

Hi,

Not yet, unfortunately. We've observed that it seems to clear up if we deploy on a Linux server. It seems to be specific with 4.0.4 (It didn't happen with 4.0.1). I inherited the issue on a Windows server, and we're now moving to redeploy on Linux.

I did discover that the timeouts often occur if the timeout for transactions is set too low for the HSQL database, though it shouldn't be having trouble reconnecting like this.

Good luck!
Actions

5. Re: Weird behavior with ping timeouts

vishnukn Oct 2, 2009 3:16 PM (in response to smithmb)

in my case , my jboss is not in clustered, but why should it need to do the ping and pong, is there some thing i need to do in the configuration to stop this.

2009-10-02 03:04:53,140 WARN [org.jboss.mq.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:1277)
 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.

6. Re: Weird behavior with ping timeouts

b.eckenfels Oct 2, 2009 5:18 PM (in response to smithmb)

First of all, you abolsutely must register an error listener if you want to recover from problems.

Usual reasons for this pong timeout are:

- long garbage collection times in one of the participating JVMs
- delays in the database when you use jdbc persistence
- network problems
- os virtualization freezes (like vmotion)

Greetings
Bernd
Actions

Go to original post