ping timeout after successful reconnect to server

[catherinelo]

JBoss version : 4.0.1SP1

I have a JMS Client that register to exceptionListener. But I got ping timeout exception even though successfully reconnect to server.

Here is part of my code:

private class ExceptionListenerImpl implements ExceptionListener {
 public void onException(JMSException ex) {
 currentThread = Thread.currentThread();
 logger.info("JMS provider failure detected: " + ex.getMessage());

 boolean restartInvoker = true;
 while (restartInvoker && running) {
 logger.debug("Trying to reconnect to JMS provider");

 try {
 try {
 Thread.sleep(reconnectInterval);
 } catch (InterruptedException ie) {
 return;
 }

 // Reboot container
 stopConnection();
 createConnection();

 restartInvoker = false;
 logger.debug("Successfully reconnect to JMS");
 } catch (Exception e) {
 logger.error("Reconnect failed: JMS provider failure detected " + e.getMessage());
 }
 }
 currentThread = null;
}
}

Here is the error:
org.jboss.mq.SpyJMSException: Connection Failed; - nested throwable: (java.io.IOException: ping time
out.)
at org.jboss.mq.Connection.asynchFailure(Connection.java:436)
at org.jboss.mq.Connection$PingTask.run(Connection.java:1385)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Unknown Source)
Caused by: java.io.IOException: ping timeout.
at org.jboss.mq.Connection$PingTask.run(Connection.java:1377)
... 2 more


Refered to this page : http://wiki.jboss.org/wiki/Wiki.jsp?page=IGetIOExceptionPingTimeoutHowDoIFixIt and added log4j.category.org.jboss.mq=TRACE#org.jboss.logging.XLevel to get the trace.

Seems like the old connection (ConnectionToken:ID:8/e6705f73a40518b6c1840f7c417e267e) is still running although I have successfully reconnected to the server with a new connection (ConnectionToken:4/2fe5a18970c262e7de045654896421c7). Am I right?

Here is the trace:

TRACE: 2005-08-17 18:35:55,975 [Connection] PING 1124274955975 Connection@30931963[token=ConnectionT
oken:4/2fe5a18970c262e7de045654896421c7 rcvstate=STARTED]
...
TRACE: 2005-08-17 18:35:55,985 [Connection] PONG serverTime=1124274955975 Connection@30931963[token=
ConnectionToken:4/2fe5a18970c262e7de045654896421c7 rcvstate=STARTED]

TRACE: 2005-08-17 18:35:09,629 [Connection] Notified of failure reason=Connection Failed Connection@
29232906[token=ConnectionToken:ID:8/e6705f73a40518b6c1840f7c417e267e rcvstate=STOPPED]
java.io.IOException: ping timeout.
at org.jboss.mq.Connection$PingTask.run(Connection.java:1377)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Unknown Source)
WARN : 2005-08-17 18:35:09,629 [Connection] Connection failure:
org.jboss.mq.SpyJMSException: Connection Failed; - nested throwable: (java.io.IOException: ping time
out.)
at org.jboss.mq.Connection.asynchFailure(Connection.java:436)
at org.jboss.mq.Connection$PingTask.run(Connection.java:1385)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Unknown Source)
Caused by: java.io.IOException: ping timeout.
at org.jboss.mq.Connection$PingTask.run(Connection.java:1377)
... 2 more


I really have no idea on how to fix this problem. Please help. Thanks.

[adrian.brock]

Unfortunately, you have been singled out as an example:
http://www.jboss.org/index.html?module=bb&op=viewtopic&t=68044
http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossHelp

http://wiki.jboss.org/wiki/Wiki.jsp?page=BadPostShort
So you don't post the most important information, i.e. what does this do:

stopConnection();

You also don't show the history of the problematic connection.
i.e. where is the previous logging for this connection:

ConnectionToken:ID:8/e6705f73a40518b6c1840f7c417e267e

I can tell just by looking at the client id (number 8),
that it was actually created AFTER the one that is working (number 4)

TRACE: 2005-08-17 18:35:55,985 [Connection] PONG serverTime=1124274955975 Connection@30931963[token=
ConnectionToken:4/2fe5a18970c262e7de045654896421c7 rcvstate=STARTED]

[catherinelo]

Hi,
Thanks for the reply.

Here is the code for createConnection
[Code]
protected void createConnection() throws NamingException, JMSException {
logger.debug("establish the connection...");
InitialContext iniCtx = new InitialContext(properties);
Object tmp = iniCtx.lookup("ConnectionFactory");
qcf = (QueueConnectionFactory) tmp;
stateQueue = (Queue) iniCtx.lookup("queue/StateQueue");
usageQueue = (Queue) iniCtx.lookup("queue/UsageQueue");
errorQueue = (Queue) iniCtx.lookup("queue/ErrorQueue");
queueConnection = qcf.createQueueConnection();
queueConnection.setExceptionListener(exListener);
queueConnection.start();
}
[/Code]


Here is the code for stopConnection

[Code]
protected void stopConnection() {
try {
if (queueConnection != null) {
queueConnection.setExceptionListener(null);
queueConnection.stop();
queueConnection.close();
}
} catch (Exception ex) {
logger.error("Error when try to stop Connection = " + ex.getMessage());
}

if (queueConnection != null)
queueConnection = null;
}
[/Code]


I have recaptured the TRACE, so the connection token ID is different from the previous one that I posted previously.


Here is part of the trace when I started the client, the connection token Id (15):

TRACE: 2005-08-18 09:44:23,343 [Connection] PING 1124329463343 Connection@31822120[token=ConnectionT
oken:ID:15/704e049760ee15c515267c87a72b044b rcvstate=STARTED]
TRACE: 2005-08-18 09:44:23,343 [SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.i
l.uil2.msgs.PingMsg33431531[msgType: m_ping, msgID: 8, error: null]
TRACE: 2005-08-18 09:44:23,343 [SocketManager$WriteTask] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg33431531[msgType: m_ping, msgID: 8, error: null]
TRACE: 2005-08-18 09:44:23,343 [SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msg
s.PingMsg33431531[msgType: m_ping, msgID: 8, error: null]
TRACE: 2005-08-18 09:44:23,353 [SocketManager$ReadTask] Read msgType: m_pong, msgID: -2147480190
TRACE: 2005-08-18 09:44:23,353 [SocketManager$ReadTask] Read new msg: org.jboss.mq.il.uil2.msgs.Ping
Msg14780827[msgType: m_pong, msgID: -2147480190, error: null]
TRACE: 2005-08-18 09:44:23,353 [UILClientILService] Begin handleMsg, msgType: 24
TRACE: 2005-08-18 09:44:23,353 [Connection] PONG serverTime=1124329463353 Connection@31822120[token=
ConnectionToken:ID:15/704e049760ee15c515267c87a72b044b rcvstate=STARTED]


Here is the trace when I stoped the server, and client was able to detect the connection failure:

INFO : 2005-08-18 09:45:13,465 [JMSManager$ExceptionListenerImpl] JMS provider failure detected: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
DEBUG: 2005-08-18 09:45:13,465 [JMSManager$ExceptionListenerImpl] Trying to reconnect to JMS provider
TRACE: 2005-08-18 09:45:23,349 [Connection] PING 1124329523349 Connection@31822120[token=ConnectionToken:ID:15/704e049760ee15c515267c87a72b044b rcvstate=STARTED]
TRACE: 2005-08-18 09:45:23,359 [Connection] Notified of failure reason=Connection Failed Connection@31822120[token=ConnectionToken:ID:15/704e049760ee15c515267c87a72b044b rcvstate=STARTED]
java.io.IOException: Client is not connected
at org.jboss.mq.il.uil2.SocketManager.internalSendMessage(SocketManager.java:233)
at org.jboss.mq.il.uil2.SocketManager.sendReply(SocketManager.java:219)
at org.jboss.mq.il.uil2.UILServerIL.ping(UILServerIL.java:462)
at org.jboss.mq.Connection.pingServer(Connection.java:927)
at org.jboss.mq.Connection$PingTask.run(Connection.java:1381)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Unknown Source)
TRACE: 2005-08-18 09:45:23,470 [Connection] Stopping connection Connection@31822120[token=ConnectionToken:ID:15/704e049760ee15c515267c87a72b044b rcvstate=STOPPED]
ERROR: 2005-08-18 09:45:23,480 [JMSManager] Error when try to stop Connection = Cannot disable the connection with the JMS server; - nested throwable: (java.io.IOException: Client is not connected)
DEBUG: 2005-08-18 09:45:23,500 [JMSManager] establish the connection...
DEBUG: 2005-08-18 09:45:24,481 [NamingContext] Failed to connect to 192.168.7.51:1099
javax.naming.CommunicationException: Failed to connect to server 192.168.7.51:1099 [Root exception is javax.naming.ServiceUnavailableException: Failed to connect to server 192.168.7.51:1099 [Root exception is java.net.ConnectException: Connection refused: connect]]
at org.jnp.interfaces.NamingContext.getServer(NamingContext.java:215)
at org.jnp.interfaces.NamingContext.checkRef(NamingContext.java:1227)
at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:527)
at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:520)
at javax.naming.InitialContext.lookup(Unknown Source)
at com.streetspace.webstation.client.JMSManager.createConnection(JMSManager.java:85)
at com.streetspace.webstation.client.JMSManager$ExceptionListenerImpl.connectThread(JMSManag
er.java:216)
at com.streetspace.webstation.client.JMSManager$ExceptionListenerImpl.onException(JMSManager
.java:191)
at org.jboss.mq.Connection.asynchFailure(Connection.java:446)
at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:145)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:406)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:338)
at java.lang.Thread.run(Unknown Source)
Caused by: javax.naming.ServiceUnavailableException: Failed to connect to server 192.168.7.51:1099 [
Root exception is java.net.ConnectException: Connection refused: connect]
at org.jnp.interfaces.NamingContext.getServer(NamingContext.java:189)
... 12 more
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(Unknown Source)
at java.net.PlainSocketImpl.connectToAddress(Unknown Source)
at java.net.PlainSocketImpl.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.(Unknown Source)
at java.net.Socket.(Unknown Source)
at org.jnp.interfaces.TimedSocketFactory.createSocket(TimedSocketFactory.java:69)
at org.jnp.interfaces.TimedSocketFactory.createSocket(TimedSocketFactory.java:62)
at org.jnp.interfaces.NamingContext.getServer(NamingContext.java:185)
... 12 more
ERROR: 2005-08-18 09:45:29,769 [JMSManager$ExceptionListenerImpl] Reconnect failed: JMS provider failure detected Receive timed out


Here is the trace when I started back the server and client tried to reconnect back to the JMS provider. A new connection with connection token Id (2) started:

DEBUG: 2005-08-18 09:47:36,871 [JMSManager$ExceptionListenerImpl] Trying to reconnect to JMS provider
DEBUG: 2005-08-18 09:47:46,876 [JMSManager] establish the connection...
DEBUG: 2005-08-18 09:47:46,906 [SpyConnectionFactoryObjectFactory] Extracting SpyConnectionFactory from reference
DEBUG: 2005-08-18 09:47:46,926 [SpyConnectionFactoryObjectFactory] The GenericConnectionFactory is:
GenericConnectionFactory[server=org.jboss.mq.il.uil2.UILServerIL@32784a connectionProperties={UIL_ADDRESS_KEY=192.168.7.51, UIL_CHUNKSIZE_KEY=1000000, UIL_TCPNODELAY_KEY=yes, ClientILService=org.jboss
.mq.il.uil2.UILClientILService, UIL_PORT_KEY=8093, UIL_BUFFERSIZE_KEY=2048, PingPeriod=60000}]
DEBUG: 2005-08-18 09:47:46,936 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
DEBUG: 2005-08-18 09:47:46,956 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
DEBUG: 2005-08-18 09:47:46,966 [SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
TRACE: 2005-08-18 09:47:46,976 [Connection] Connection Initializing userName=null Connection@1049443[clientID=null rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:46,976 [Connection] Getting the serverIL Connection@1049443[clientID=null rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:46,976 [Connection] serverIL=org.jboss.mq.il.uil2.UILServerIL@14e8cee Connection@1049443[clientID=null rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:46,976 [Connection] Authenticating user null Connection@1049443[clientID=null rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:46,976 [UILServerIL] Connecting to : klws20-51/192.168.7.51:8093
TRACE: 2005-08-18 09:47:46,986 [UILServerIL] Connecting with addr=192.168.7.51, port=8093, localAddr=null, localPort=0, socketFactory=javax.net.DefaultSocketFactory@140c281, enableTcpNoDelay=true, bufferSize=2048, chunkSize=1000000
TRACE: 2005-08-18 09:47:46,986 [UILServerIL] Begin connect loop, maxRetries=10, delay=0
TRACE: 2005-08-18 09:47:46,996 [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:1160)
at org.jboss.mq.Connection.(Connection.java:255)
at org.jboss.mq.Connection.(Connection.java:332)
at org.jboss.mq.SpyConnection.(SpyConnection.java:66)
at org.jboss.mq.SpyConnectionFactory.createConnection(SpyConnectionFactory.java:87)
at org.jboss.mq.SpyConnectionFactory.createQueueConnection(SpyConnectionFactory.java:124)
at com.streetspace.webstation.client.JMSManager.createConnection(JMSManager.java:90)
at com.streetspace.webstation.client.JMSManager$ExceptionListenerImpl.connectThread(JMSManager.java:216)
at com.streetspace.webstation.client.JMSManager$ExceptionListenerImpl.onException(JMSManager.java:191)
at org.jboss.mq.Connection.asynchFailure(Connection.java:446)
at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:145)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:406)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:338)
at java.lang.Thread.run(Unknown Source)
TRACE: 2005-08-18 09:47:47,006 [SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.m
q.il.uil2.msgs.CheckUserMsg12376621[msgType: m_authenticate, msgID: 10, error: null]
DEBUG: 2005-08-18 09:47:47,016 [SocketManager$WriteTask] Begin WriteTask.run
DEBUG: 2005-08-18 09:47:47,016 [SocketManager$ReadTask] Begin ReadTask.run
DEBUG: 2005-08-18 09:47:47,016 [SocketManager$WriteTask] Created ObjectOutputStream
TRACE: 2005-08-18 09:47:47,026 [SocketManager$WriteTask] Write msg: org.jboss.mq.il.uil2.msgs.CheckU
serMsg12376621[msgType: m_authenticate, msgID: 10, error: null]
DEBUG: 2005-08-18 09:47:47,026 [SocketManager$ReadTask] Created ObjectInputStream
TRACE: 2005-08-18 09:47:47,026 [SocketManager$ReadTask] Read msgType: m_authenticate, msgID: 10
TRACE: 2005-08-18 09:47:47,036 [SocketManager$ReadTask] Found replyMap msg: org.jboss.mq.il.uil2.msg
s.CheckUserMsg12376621[msgType: m_authenticate, msgID: 10, error: null]
TRACE: 2005-08-18 09:47:47,036 [SocketManager$ReadTask] Read msg reply: org.jboss.mq.il.uil2.msgs.Ch
eckUserMsg12376621[msgType: m_authenticate, msgID: 10, error: null]
TRACE: 2005-08-18 09:47:47,036 [SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msg
s.CheckUserMsg12376621[msgType: m_authenticate, msgID: 10, error: null]
TRACE: 2005-08-18 09:47:47,036 [Connection] Starting the client il Connection@1049443[clientID=null rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,046 [GenericConnectionFactory] Handing out ClientIL: org.jboss.mq.il.uil2.UILClientILService
DEBUG: 2005-08-18 09:47:47,046 [UILClientILService] Starting
TRACE: 2005-08-18 09:47:47,056 [Connection] Using client id org.jboss.mq.il.uil2.UILClientILService@97d01f Connection@1049443[clientID=null rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,056 [SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.m
q.il.uil2.msgs.ConnectionTokenMsg14721926[msgType: m_setSpyDistributedConnection, msgID: 11, error:
null]
TRACE: 2005-08-18 09:47:47,056 [SocketManager$WriteTask] Write msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14721926[msgType: m_setSpyDistributedConnection, msgID: 11, error: null]
TRACE: 2005-08-18 09:47:47,076 [SocketManager$ReadTask] Read msgType: m_setSpyDistributedConnection, msgID: 11
TRACE: 2005-08-18 09:47:47,076 [SocketManager$ReadTask] Found replyMap msg: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14721926[msgType: m_setSpyDistributedConnection, msgID: 11, error: null]
TRACE: 2005-08-18 09:47:47,076 [SocketManager$ReadTask] Read msg reply: org.jboss.mq.il.uil2.msgs.ConnectionTokenMsg14721926[msgType: m_setSpyDistributedConnection, msgID: 11, error: null]
TRACE: 2005-08-18 09:47:47,076 [SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msg
s.ConnectionTokenMsg14721926[msgType: m_setSpyDistributedConnection, msgID: 11, error: null]
TRACE: 2005-08-18 09:47:47,076 [Connection] Creating XAResourceManager Connection@1049443[token=Conn
ectionToken:null/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,086 [Connection] Starting the ping thread Connection@1049443[token=ConnectionToken:null/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,086 [Connection] Connection establishment successful Connection@1049443[token=ConnectionToken:null/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,086 [Connection] Checking clientID=null Connection@1049443[token=ConnectionToken:null/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,096 [Connection] Ask for an id Connection@1049443[token=ConnectionToken:null/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,096 [SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.m
q.il.uil2.msgs.GetIDMsg23668144[msgType: m_getID, msgID: 12, error: null]
TRACE: 2005-08-18 09:47:47,096 [SocketManager$WriteTask] Write msg: org.jboss.mq.il.uil2.msgs.GetIDMsg23668144[msgType: m_getID, msgID: 12, error: null]
TRACE: 2005-08-18 09:47:47,106 [SocketManager$ReadTask] Read msgType: m_getID, msgID: 12
TRACE: 2005-08-18 09:47:47,106 [SocketManager$ReadTask] Found replyMap msg: org.jboss.mq.il.uil2.msg
s.GetIDMsg23668144[msgType: m_getID, msgID: 12, error: null]
TRACE: 2005-08-18 09:47:47,106 [SocketManager$ReadTask] Read msg reply: org.jboss.mq.il.uil2.msgs.GetIDMsg23668144[msgType: m_getID, msgID: 12, error: null]
TRACE: 2005-08-18 09:47:47,106 [SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msg
s.GetIDMsg23668144[msgType: m_getID, msgID: 12, error: null]
TRACE: 2005-08-18 09:47:47,116 [Connection] ClientID established Connection@1049443[token=ConnectionToken:ID:2/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STOPPED]
TRACE: 2005-08-18 09:47:47,116 [Connection] Starting connection Connection@1049443[token=ConnectionToken:ID:2/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STARTED]
TRACE: 2005-08-18 09:47:47,116 [SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.m
q.il.uil2.msgs.EnableConnectionMsg2719739[msgType: m_setEnabled, msgID: 13, error: null]
TRACE: 2005-08-18 09:47:47,126 [SocketManager$WriteTask] Write msg: org.jboss.mq.il.uil2.msgs.Enable
ConnectionMsg2719739[msgType: m_setEnabled, msgID: 13, error: null]
TRACE: 2005-08-18 09:47:47,126 [SocketManager$ReadTask] Read msgType: m_setEnabled, msgID: 13
TRACE: 2005-08-18 09:47:47,126 [SocketManager$ReadTask] Found replyMap msg: org.jboss.mq.il.uil2.msg
s.EnableConnectionMsg2719739[msgType: m_setEnabled, msgID: 13, error: null]
TRACE: 2005-08-18 09:47:47,126 [SocketManager$ReadTask] Read msg reply: org.jboss.mq.il.uil2.msgs.EnableConnectionMsg2719739[msgType: m_setEnabled, msgID: 13, error: null]
TRACE: 2005-08-18 09:47:47,126 [SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msg
s.EnableConnectionMsg2719739[msgType: m_setEnabled, msgID: 13, error: null]
DEBUG: 2005-08-18 09:47:47,136 [JMSManager$ExceptionListenerImpl] Successfully reconnect to JMS


Here is the trace I got instantly after successfully reconnect to JMS:

TRACE: 2005-08-18 09:47:47,136 [Connection] Notified of failure reason=Connection Failed Connection@31822120[token=ConnectionToken:ID:15/704e049760ee15c515267c87a72b044b rcvstate=STOPPED]
java.io.IOException: ping timeout.
at org.jboss.mq.Connection$PingTask.run(Connection.java:1377)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Unknown Source)
WARN : 2005-08-18 09:47:47,136 [Connection] Connection failure:
org.jboss.mq.SpyJMSException: Connection Failed; - nested throwable: (java.io.IOException: ping time
out.)
at org.jboss.mq.Connection.asynchFailure(Connection.java:436)
at org.jboss.mq.Connection$PingTask.run(Connection.java:1385)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Unknown Source)
Caused by: java.io.IOException: ping timeout.
at org.jboss.mq.Connection$PingTask.run(Connection.java:1377)
... 2 more
TRACE: 2005-08-18 09:47:47,146 [SocketManager$WriteTask] WriteTask was interrupted
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(LinkedQueue.java:122)
at org.jboss.mq.il.uil2.SocketManager$WriteTask.run(SocketManager.java:485)
at java.lang.Thread.run(Unknown Source)
DEBUG: 2005-08-18 09:47:47,146 [SocketManager$ReadTask] End ReadTask.run
DEBUG: 2005-08-18 09:47:47,146 [SocketManager$WriteTask] End WriteTask.run
TRACE: 2005-08-18 09:47:47,146 [Connection] PING 1124329667146 Connection@1049443[token=ConnectionToken:ID:2/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STARTED]
TRACE: 2005-08-18 09:47:47,156 [SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.i
l.uil2.msgs.PingMsg9523050[msgType: m_ping, msgID: 14, error: null]
TRACE: 2005-08-18 09:47:47,156 [SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msg
s.PingMsg9523050[msgType: m_ping, msgID: 14, error: null]
TRACE: 2005-08-18 09:47:47,156 [SocketManager$WriteTask] Write msg: org.jboss.mq.il.uil2.msgs.PingMs
g9523050[msgType: m_ping, msgID: 14, error: null]
TRACE: 2005-08-18 09:47:47,156 [SocketManager$ReadTask] Read msgType: m_pong, msgID: -2147483642
TRACE: 2005-08-18 09:47:47,156 [SocketManager$ReadTask] Read new msg: org.jboss.mq.il.uil2.msgs.Ping
Msg32820206[msgType: m_pong, msgID: -2147483642, error: null]
TRACE: 2005-08-18 09:47:47,166 [UILClientILService] Begin handleMsg, msgType: 24
TRACE: 2005-08-18 09:47:47,166 [Connection] PONG serverTime=1124329667156 Connection@1049443[token=ConnectionToken:ID:2/ab48c86f41f1f3ab8b7be5243a1eeb29 rcvstate=STARTED]

Any idea why the client receive notification on connection failure for Connection Token Id 15?
How to resolve this problem?
Please let me know if the information that I provided is insufficient.
Please help. Thanks

[adrian.brock]

Incredible.

You don't even have to enable TRACE logging to see the problem,
because you have your own error message (lacking a stacktrace).

ERROR: 2005-08-18 09:45:23,480 [JMSManager] Error when try to stop Connection = Cannot disable the connection with the JMS server; - nested throwable: (java.io.IOException: Client is not connected)

I've augmented the FAQ with this question, usually it is session.close().
http://wiki.jboss.org/wiki/Wiki.jsp?page=IGetIOExceptionPingTimeoutHowDoIFixIt

Although this is really a "How do I code Java" FAQ.
Your code gets chosen as "WHAT NOT TO DO".

[catherinelo]

Hi,
Thanks for the reply.

It works. Thank you very much.

[vbijjargi]

Hi,

I am still getting the same error. Could you please help me out.


my connect method is as below:

public void connectToQueue() throws NamingException, JMSException {
log.info("connecting to JMS Queue");

try {

// Get appserver IP and port from application session
appServerIP = (String) applicationSession.getProperty(SC.JBOSS_SERVER_IP);
jmsPort = (String) applicationSession.getProperty(SC.JMS_PORT);

// get connection properties and context
properties = new Properties();
properties.put(Context.INITIAL_CONTEXT_FACTORY, SC.INITIAL_CONTEXT_FACTORY);
properties.put(Context.URL_PKG_PREFIXES, SC.URL_PKG_PREFIXES);
properties.put(Context.PROVIDER_URL, SC.PROVIDER_URL_PROTOCOL + appServerIP + ":"+ jmsPort);
iniCtx = new InitialContext(properties);

// get connected to the JMS queue
queueConnection = ((QueueConnectionFactory) iniCtx.lookup("ConnectionFactory")).createQueueConnection();
queueConnection.start();
connectedToQueue = true;

log.debug("connected with JMS queue");
} catch (NamingException ne) {
log.error("exception in connectToQueue method -" + ne);
connectedToQueue = false;
throw ne;
} catch (JMSException jmse) {
log.error("exception in connectToQueue method -" + jmse);
connectedToQueue = false;
throw jmse;
}
}

Now it reads the messages from queue. I have more than 10 messages per second and suddenly I get the pong timeout message. It appears periodically.

Please help

[hskiran]

Hi Cathernilo,

Even I am facing the same problem, the pong timeout exception which u received.

If you have the full implementation of the ExceptionListenerImpl class, can you pls paste it here.

Thanks.
hskiran