4 Replies Latest reply on Mar 16, 2006 8:16 PM by nealang

    Exceptions thrown during HAJMS failover

    nealang

      Hi All,

      We have set up a cluster of 2 JBoss 4.0.2 AS on two separate machines running with the All configuration. Our ejb.jar module
      is deployed on both nodes in '/jboss-4.0.2/server/all/deploy'. Both nodes also has the same 'jbossmq-destinations-service.xml'
      in '/jboss-4.0.2/server/all/deploy-hasingleton/jms'.

      We're making use of JBoss's HAJMS singleton fail-over as a failover scheme such that if the Master Node fails, the second node will take over and our mdbs can continue listening to the queues administrated and continue serving messages.

      Everything works fine and good, one of the nodes get selected as Master, and handles all JMS traffic. But when the Master node fails (forced shutdown during testing) and the second node starts to take over, the second node throws a screenfull of exceptions as follows:

      2006-03-13 15:24:46,946 WARN [org.jboss.ejb.plugins.jms.JMSContainerInvoker] JMS provider failure detected:
      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
       at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
       at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
       at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: java.net.SocketException: Connection reset
       at java.net.SocketInputStream.read(SocketInputStream.java:168)
       at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
       at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
       at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
       at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
       at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
       at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
       at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
       at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)
       ... 1 more
      2006-03-13 15:24:46,946 WARN [org.jboss.mq.Connection] Connection failure, use javax.jms.Connection.setExceptionListener() to handle this error and reconnect
      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
       at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
       at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
       at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: java.net.SocketException: Connection reset
       at java.net.SocketInputStream.read(SocketInputStream.java:168)
       at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
       at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
       at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
       at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
       at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
       at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
       at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
       at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)
       ... 1 more
      2006-03-13 15:24:46,946 WARN [org.jboss.mq.Connection] Connection failure, use javax.jms.Connection.setExceptionListener() to handle this error and reconnect
      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
       at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
       at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
       at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: java.net.SocketException: Connection reset
       at java.net.SocketInputStream.read(SocketInputStream.java:168)
       at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
       at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
       at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
       at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
       at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
       at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
       at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
       at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)
       ... 1 more
      2006-03-13 15:24:46,946 WARN [org.jboss.ejb.plugins.jms.JMSContainerInvoker] JMS provider failure detected:
      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
       at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
       at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
       at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: java.net.SocketException: Connection reset
       at java.net.SocketInputStream.read(SocketInputStream.java:168)
       at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
       at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
       at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
       at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
       at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
       at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
       at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
       at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)
       ... 1 more
      2006-03-13 15:24:46,946 WARN [org.jboss.mq.Connection] Connection failure, use javax.jms.Connection.setExceptionListener() to handle this error and reconnect
      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
       at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
       at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
       at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: java.net.SocketException: Connection reset
       at java.net.SocketInputStream.read(SocketInputStream.java:168)
       at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
       at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
       at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
       at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
       at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
       at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
       at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
       at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)
       ... 1 more
      2006-03-13 15:24:46,946 WARN [org.jboss.ejb.plugins.jms.JMSContainerInvoker] JMS provider failure detected:
      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
       at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
       at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
       at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: java.net.SocketException: Connection reset
       at java.net.SocketInputStream.read(SocketInputStream.java:168)
       at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
       at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
       at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2133)
       at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2313)
       at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2380)
       at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2452)
       at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2601)
       at java.io.ObjectInputStream.readByte(ObjectInputStream.java:845)
       at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)
       ... 1 more
      2006-03-13 15:24:47,118 ERROR [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Could not stop JMS connection
      org.jboss.mq.SpyJMSException: Cannot disable the connection with 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.doStop(Connection.java:1235)
       at org.jboss.mq.Connection.stop(Connection.java:696)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker.innerStop(JMSContainerInvoker.java:1001)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl.run(JMSContainerInvoker.java:1460)
       at java.lang.Thread.run(Thread.java:534)
      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.sendMessage(SocketManager.java:206)
       at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
       at org.jboss.mq.Connection.doStop(Connection.java:1231)
       ... 4 more
      2006-03-13 15:24:47,305 ERROR [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Could not stop JMS connection
      org.jboss.mq.SpyJMSException: Cannot disable the connection with 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.doStop(Connection.java:1235)
       at org.jboss.mq.Connection.stop(Connection.java:696)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker.innerStop(JMSContainerInvoker.java:1001)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl.run(JMSContainerInvoker.java:1460)
       at java.lang.Thread.run(Thread.java:534)
      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.sendMessage(SocketManager.java:206)
       at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
       at org.jboss.mq.Connection.doStop(Connection.java:1231)
       ... 4 more
      2006-03-13 15:24:47,383 ERROR [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Could not stop JMS connection
      org.jboss.mq.SpyJMSException: Cannot disable the connection with 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.doStop(Connection.java:1235)
       at org.jboss.mq.Connection.stop(Connection.java:696)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker.innerStop(JMSContainerInvoker.java:1001)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl.run(JMSContainerInvoker.java:1460)
       at java.lang.Thread.run(Thread.java:534)
      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.sendMessage(SocketManager.java:206)
       at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
       at org.jboss.mq.Connection.doStop(Connection.java:1231)
       ... 4 more
      2006-03-13 15:24:47,540 ERROR [org.jboss.ejb.plugins.jms.DLQHandler] Stopping failed DLQHandler
      org.jboss.mq.SpyJMSException: Cannot disable the connection with 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.doStop(Connection.java:1235)
       at org.jboss.mq.Connection.stop(Connection.java:696)
       at org.jboss.ejb.plugins.jms.DLQHandler.stopService(DLQHandler.java:177)
       at org.jboss.system.ServiceMBeanSupport.jbossInternalStop(ServiceMBeanSupport.java:320)
       at org.jboss.system.ServiceMBeanSupport.stop(ServiceMBeanSupport.java:183)
       at org.jboss.system.ServiceMBeanSupport.jbossInternalDestroy(ServiceMBeanSupport.java:356)
       at org.jboss.system.ServiceMBeanSupport.destroy(ServiceMBeanSupport.java:198)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker.destroyService(JMSContainerInvoker.java:1061)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl.run(JMSContainerInvoker.java:1468)
       at java.lang.Thread.run(Thread.java:534)
      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.sendMessage(SocketManager.java:206)
       at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
       at org.jboss.mq.Connection.doStop(Connection.java:1231)
       ... 9 more
      2006-03-13 15:24:47,540 ERROR [org.jboss.ejb.plugins.jms.DLQHandler] Stopping failed DLQHandler
      org.jboss.mq.SpyJMSException: Cannot disable the connection with 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.doStop(Connection.java:1235)
       at org.jboss.mq.Connection.stop(Connection.java:696)
       at org.jboss.ejb.plugins.jms.DLQHandler.stopService(DLQHandler.java:177)
       at org.jboss.system.ServiceMBeanSupport.jbossInternalStop(ServiceMBeanSupport.java:320)
       at org.jboss.system.ServiceMBeanSupport.stop(ServiceMBeanSupport.java:183)
       at org.jboss.system.ServiceMBeanSupport.jbossInternalDestroy(ServiceMBeanSupport.java:356)
       at org.jboss.system.ServiceMBeanSupport.destroy(ServiceMBeanSupport.java:198)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker.destroyService(JMSContainerInvoker.java:1061)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl.run(JMSContainerInvoker.java:1468)
       at java.lang.Thread.run(Thread.java:534)
      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.sendMessage(SocketManager.java:206)
       at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
       at org.jboss.mq.Connection.doStop(Connection.java:1231)
       ... 9 more
      2006-03-13 15:24:47,555 ERROR [org.jboss.ejb.plugins.jms.DLQHandler] Stopping failed DLQHandler
      org.jboss.mq.SpyJMSException: Cannot disable the connection with 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.doStop(Connection.java:1235)
       at org.jboss.mq.Connection.stop(Connection.java:696)
       at org.jboss.ejb.plugins.jms.DLQHandler.stopService(DLQHandler.java:177)
       at org.jboss.system.ServiceMBeanSupport.jbossInternalStop(ServiceMBeanSupport.java:320)
       at org.jboss.system.ServiceMBeanSupport.stop(ServiceMBeanSupport.java:183)
       at org.jboss.system.ServiceMBeanSupport.jbossInternalDestroy(ServiceMBeanSupport.java:356)
       at org.jboss.system.ServiceMBeanSupport.destroy(ServiceMBeanSupport.java:198)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker.destroyService(JMSContainerInvoker.java:1061)
       at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl.run(JMSContainerInvoker.java:1468)
       at java.lang.Thread.run(Thread.java:534)
      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.sendMessage(SocketManager.java:206)
       at org.jboss.mq.il.uil2.UILServerIL.setEnabled(UILServerIL.java:189)
       at org.jboss.mq.Connection.doStop(Connection.java:1231)
       ... 9 more
      2006-03-13 15:24:49,055 INFO [org.jboss.web.tomcat.tc5.TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=file:/C:/jboss-4.0.2/server/all/deploy-hasingleton/jms/jbossmq-httpil.sar/jbossmq-httpil.war/
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.STABLE] mcasting digest [dev1:1800: [0 : 3 (3)]] (num_gossip_runs=3, max_gossip_runs=3)
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.NAKACK] sending msg #4
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.NAKACK] sent_msgs: [0 - 3]
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.UDP] sending message to 230.1.2.7:45577 (src=dev1:1800), headers are {NAKACK=[NAKACK: MSG, seqno=4, range=null], STABLE=[STABLE_GOSSIP]: digest is [dev1:1800: [0 : 3 (3)]], UDP=[UDP:group_addr=Tomcat-Cluster]}
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.UDP] received (mcast) 272 bytes from /192.168.0.167:1801 (size=272 bytes)
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.UDP] message is [dst: 230.1.2.7:45577, src: dev1:1800 (3 headers), size = 0 bytes], headers are {NAKACK=[NAKACK: MSG, seqno=4, range=null], STABLE=[STABLE_GOSSIP]: digest is [dev1:1800: [0 : 3 (3)]], UDP=[UDP:group_addr=Tomcat-Cluster]}
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.NAKACK] [dev1:1800] received <dev1:1800#4>
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.UDP] received (mcast) 272 bytes from /192.168.0.167:1801 (size=272 bytes)
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.NAKACK] receiver window for dev1:1800 is: received_msgs: [4 - 4 (size=1, missing=0)], delivered_msgs: [0 - 3]
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.STABLE] received digest dev1:1800#3 (3) from dev1:1800
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.STABLE] sending stability msg dev1:1800#3 (3)
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.STABLE] stability_task=null, delay is 743
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.UDP] message is [dst: 230.1.2.7:45577, src: dev1:1800 (3 headers), size = 0 bytes], headers are {NAKACK=[NAKACK: MSG, seqno=4, range=null], STABLE=[STABLE_GOSSIP]: digest is [dev1:1800: [0 : 3 (3)]], UDP=[UDP:group_addr=Tomcat-Cluster]}
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.NAKACK] [dev1:1800] received <dev1:1800#4>
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.stack.NakReceiverWindow] seqno 4 is smaller than 5); discarding message
      2006-03-13 15:24:49,867 DEBUG [org.jgroups.protocols.pbcast.NAKACK] receiver window for dev1:1800 is: received_msgs: [], delivered_msgs: [0 - 4]
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] sending msg #5
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] sent_msgs: [0 - 4]
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.UDP] sending message to 230.1.2.7:45577 (src=dev1:1800), headers are {NAKACK=[NAKACK: MSG, seqno=5, range=null], STABLE=[STABILITY]: digest is [dev1:1800: [-1 : 3 (3)]], UDP=[UDP:group_addr=Tomcat-Cluster]}
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.UDP] received (mcast) 272 bytes from /192.168.0.167:1801 (size=272 bytes)
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.UDP] message is [dst: 230.1.2.7:45577, src: dev1:1800 (3 headers), size = 0 bytes], headers are {NAKACK=[NAKACK: MSG, seqno=5, range=null], STABLE=[STABILITY]: digest is [dev1:1800: [-1 : 3 (3)]], UDP=[UDP:group_addr=Tomcat-Cluster]}
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] [dev1:1800] received <dev1:1800#5>
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.UDP] received (mcast) 272 bytes from /192.168.0.167:1801 (size=272 bytes)
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] receiver window for dev1:1800 is: received_msgs: [5 - 5 (size=1, missing=0)], delivered_msgs: [0 - 4]
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.STABLE] stability vector is [dev1:1800#3]
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.STABLE] cancelling stability task (running=false)
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] received digest [dev1:1800: [-1 : 3 (3)]]
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.UDP] message is [dst: 230.1.2.7:45577, src: dev1:1800 (3 headers), size = 0 bytes], headers are {NAKACK=[NAKACK: MSG, seqno=5, range=null], STABLE=[STABILITY]: digest is [dev1:1800: [-1 : 3 (3)]], UDP=[UDP:group_addr=Tomcat-Cluster]}
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] [dev1:1800] received <dev1:1800#5>
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.stack.NakReceiverWindow] seqno 5 is smaller than 6); discarding message
      2006-03-13 15:24:50,617 DEBUG [org.jgroups.protocols.pbcast.NAKACK] receiver window for dev1:1800 is: received_msgs: [], delivered_msgs: [0 - 5]
      2006-03-13 15:24:51,289 INFO [org.jboss.mq.server.jmx.Queue.routerAgtQ] Bound to JNDI name: queue/routerAgtQ
      2006-03-13 15:24:51,289 INFO [org.jboss.mq.server.jmx.Queue.routerAppQ] Bound to JNDI name: queue/routerAppQ
      2006-03-13 15:24:51,289 INFO [org.jboss.mq.server.jmx.Queue.routerInQ] Bound to JNDI name: queue/routerInQ
      2006-03-13 15:24:51,289 INFO [org.jboss.mq.server.jmx.Queue.routerReplyInQ] Bound to JNDI name: queue/routerReplyInQ
      2006-03-13 15:24:51,289 INFO [org.jboss.mq.server.jmx.Queue.routerReplyOutQ] Bound to JNDI name: queue/routerReplyOutQ
      2006-03-13 15:24:51,304 INFO [org.jboss.mq.server.jmx.Queue.in_agt1q] Bound to JNDI name: queue/in_agt1q
      2006-03-13 15:24:51,304 INFO [org.jboss.mq.server.jmx.Queue.in_agt2q] Bound to JNDI name: queue/in_agt2q
      2006-03-13 15:24:51,304 INFO [org.jboss.mq.server.jmx.Queue.in_agt3q] Bound to JNDI name: queue/in_agt3q
      2006-03-13 15:24:51,304 INFO [org.jboss.mq.server.jmx.Queue.in_agt4q] Bound to JNDI name: queue/in_agt4q
      2006-03-13 15:24:51,304 INFO [org.jboss.mq.server.jmx.Queue.in_app1q] Bound to JNDI name: queue/in_app1q
      2006-03-13 15:24:51,320 INFO [org.jboss.mq.server.jmx.Queue.in_app2q] Bound to JNDI name: queue/in_app2q
      2006-03-13 15:24:51,320 INFO [org.jboss.mq.server.jmx.Queue.out_agt1q] Bound to JNDI name: queue/out_agt1q
      2006-03-13 15:24:51,320 INFO [org.jboss.mq.server.jmx.Queue.out_app1q] Bound to JNDI name: queue/out_app1q
      2006-03-13 15:24:51,320 INFO [org.jboss.mq.server.jmx.Queue.in_smppAgtQ] Bound to JNDI name: queue/in_smppAgtQ
      2006-03-13 15:24:51,351 INFO [org.jboss.mq.server.jmx.Topic.testTopic] Bound to JNDI name: topic/testTopic
      2006-03-13 15:24:51,351 INFO [org.jboss.mq.server.jmx.Queue.testQueue] Bound to JNDI name: queue/testQueue
      2006-03-13 15:24:51,523 INFO [org.jboss.mq.il.uil2.UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093
      2006-03-13 15:24:51,554 INFO [org.jboss.mq.server.jmx.Queue.DLQ] Bound to JNDI name: queue/DLQ
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] header is [Header: name=MessageDispatcher, type=REQ, id=1142234684152, rsp_expected=false], dest_mbrs=[dev1:1793 (additional data: 18 bytes)]
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] calling (org.jboss.ha.framework.server.HAPartitionImpl) with request 1142234684152
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] header is [Header: name=MessageDispatcher, type=REQ, id=1142234684153, rsp_expected=false], dest_mbrs=[dev1:1793 (additional data: 18 bytes)]
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] calling (org.jboss.ha.framework.server.HAPartitionImpl) with request 1142234684153
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] header is [Header: name=MessageDispatcher, type=REQ, id=1142234684154, rsp_expected=false], dest_mbrs=[dev1:1793 (additional data: 18 bytes)]
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] calling (org.jboss.ha.framework.server.HAPartitionImpl) with request 1142234684154
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] header is [Header: name=MessageDispatcher, type=REQ, id=1142234684155, rsp_expected=false], dest_mbrs=[dev1:1793 (additional data: 18 bytes)]
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] calling (org.jboss.ha.framework.server.HAPartitionImpl) with request 1142234684155
      2006-03-13 15:24:51,617 INFO [org.jboss.ha.framework.interfaces.HAPartition.lifecycle.DefaultPartition] New cluster view for partition DefaultPartition (id: 4, delta: -1) : [192.168.0.167:1099]
      2006-03-13 15:24:51,617 DEBUG [org.jgroups.blocks.RequestCorrelator] discarded request from dev1:1793 (additional data: 18 bytes) as we are not part of destination list (local_addr=dev1:1793 (additional data: 18 bytes), hdr=[Header: name=MessageDispatcher, type=REQ, id=1142234684493, rsp_expected=false], dest_mbrs=[DEV3:2341 (additional data: 17 bytes)])
      2006-03-13 15:24:57,537 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Trying to reconnect to JMS provider
      2006-03-13 15:24:57,537 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Trying to reconnect to JMS provider
      2006-03-13 15:24:57,553 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Trying to reconnect to JMS provider
      2006-03-13 15:24:57,756 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Reconnected to JMS provider
      2006-03-13 15:24:57,756 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Reconnected to JMS provider
      2006-03-13 15:24:57,772 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Reconnected to JMS provider
      


      It is noticed that the exceptions were thrown before the second node's jms provider takes over and binds the destinations and then finally trys to reconnect to JMS provider. After this the second node seemed to be able to continue handling the JMS messages.

      Even so, the above stack trace is a cause for concern for us, thus we would appreciate if anyone can help us
      shed some light on why the HAJMS is throwing stacktraces when the Master node fails over and how to make the failover
      as seamless as possible (i.e. no nasty stacktraces).

      Our configurations as follows:
      Application Server: JBoss 4.0.2
      OS: Win2k

      jbossmq-destinations-service.xml (deployed in '/jboss-4.0.2/server/all/deploy-hasingleton/jms'):
      <?xml version="1.0" encoding="UTF-8"?>
      
      <!-- $Id: jbossmq-destinations-service.xml,v 1.4.6.1 2004/11/16 04:32:39 ejort Exp $ -->
      
      <!--
       | This file defines the default Queues and Topics that JBossMQ
       | ships with. The default Queues and Topics are used by the
       | JBoss test suite and by the sample jms programs.
       |
       | You can add other destinations to this file, or you can create other
       | *-service.xml files to contain your application's destinations.
       -->
      
      <server>
       <!-- Destination without a configured SecurityManager or without a
       a SecurityConf will default to role guest with read=true, write=true,
       create=false.
       -->
      
       <mbean code="org.jboss.mq.server.jmx.Topic"
       name="jboss.mq.destination:service=Topic,name=testTopic">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       <depends optional-attribute-name="SecurityManager">jboss.mq:service=SecurityManager</depends>
       <attribute name="SecurityConf">
       <security>
       <role name="guest" read="true" write="true"/>
       <role name="publisher" read="true" write="true" create="false"/>
       <role name="durpublisher" read="true" write="true" create="true"/>
       </security>
       </attribute>
       </mbean>
      
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=testQueue">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       <depends optional-attribute-name="SecurityManager">jboss.mq:service=SecurityManager</depends>
       <attribute name="MessageCounterHistoryDayLimit">-1</attribute>
       <attribute name="SecurityConf">
       <security>
       <role name="guest" read="true" write="true"/>
       <role name="publisher" read="true" write="true" create="false"/>
       <role name="noacc" read="false" write="false" create="false"/>
       </security>
       </attribute>
       </mbean>
      
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=routerAgtQ">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=routerAppQ">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=routerInQ">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=routerReplyInQ">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=routerReplyOutQ">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_agt1q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_agt2q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_agt3q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_agt4q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
      
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_app1q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_app2q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
      
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=out_agt1q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
      
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=out_app1q">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
      
       <mbean code="org.jboss.mq.server.jmx.Queue"
       name="jboss.mq.destination:service=Queue,name=in_smppAgtQ">
       <depends optional-attribute-name="DestinationManager">jboss.mq:service=DestinationManager</depends>
       </mbean>
      
      </server>
      


      hajndi-jms-ds.xml (deployed in '/jboss-4.0.2/server/all/deploy/jms'):
      <?xml version="1.0" encoding="UTF-8"?>
      
      <connection-factories>
      
       <!-- ==================================================================== -->
       <!-- JMS Stuff -->
       <!-- ==================================================================== -->
      
       <!-- The JMS provider loader -->
       <mbean code="org.jboss.jms.jndi.JMSProviderLoader"
       name="jboss.mq:service=JMSProviderLoader,name=HAJNDIJMSProvider">
       <attribute name="ProviderName">DefaultJMSProvider</attribute>
       <attribute name="ProviderAdapterClass">
       org.jboss.jms.jndi.JNDIProviderAdapter
       </attribute>
       <!-- The combined connection factory -->
       <attribute name="FactoryRef">java:/XAConnectionFactory</attribute>
       <!-- The queue connection factory -->
       <attribute name="QueueFactoryRef">XAConnectionFactory</attribute>
       <!-- The topic factory -->
       <attribute name="TopicFactoryRef">XAConnectionFactory</attribute>
       <!-- Access JMS via HAJNDI -->
       <attribute name="Properties">
       java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory
       java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces
       java.naming.provider.url=localhost:1100
       </attribute>
       </mbean>
      
       <!-- The server session pool for Message Driven Beans -->
       <mbean code="org.jboss.jms.asf.ServerSessionPoolLoader"
       name="jboss.mq:service=ServerSessionPoolMBean,name=StdJMSPool">
       <depends optional-attribute-name="XidFactory">jboss:service=XidFactory</depends>
       <attribute name="PoolName">StdJMSPool</attribute>
       <attribute name="PoolFactoryClass">
       org.jboss.jms.asf.StdServerSessionPoolFactory
       </attribute>
       </mbean>
      
       <!-- JMS XA Resource adapter, use this to get transacted JMS in beans -->
       <tx-connection-factory>
       <jndi-name>JmsXA</jndi-name>
       <xa-transaction/>
       <rar-name>jms-ra.rar</rar-name>
       <connection-definition>org.jboss.resource.adapter.jms.JmsConnectionFactory</connection-definition>
       <config-property name="SessionDefaultType" type="java.lang.String">javax.jms.Topic</config-property>
       <config-property name="JmsProviderAdapterJNDI" type="java.lang.String">java:/DefaultJMSProvider</config-property>
       <max-pool-size>20</max-pool-size>
       <security-domain-and-application>JmsXARealm</security-domain-and-application>
       </tx-connection-factory>
      
      </connection-factories>
      


      The exceptions thrown in the second node during failover is a cause for concern. We would greatly appreciate any advice on this and help us make the failover as seamless as possible.

      Thank you in advance!


        • 1. Re: Exceptions thrown during HAJMS failover
          brian.stansberry

          The logging you are seeing is the normal activity of the JMSContainerInvoker detecting that the JMS server has failed.

          The initial WARN messages are entirely appropriate -- they are logging the fact that the connection to the JMS server has been broken.

          The subsequent ERROR messages are at too high a logging level. The JMSContainerInvoker is catching the exceptions and handling them appropriately. Appropriately, except for the fact that it logs the exceptions at ERROR. Beginning with JBoss 4.0.4.RC1 these log entries have been reduced to TRACE level.

          • 2. Re: Exceptions thrown during HAJMS failover
            nealang

            Hi Brian,

            Thanks for your reply, does this mean that everything is actually ok?

            • 3. Re: Exceptions thrown during HAJMS failover
              brian.stansberry

              Yes, everything is OK. In your log snippet, after all the ERROR messages, you see a lot of entries like this:

              2006-03-13 15:24:51,289 INFO [org.jboss.mq.server.jmx.Queue.routerAgtQ] Bound to JNDI name: queue/r
              outerAgtQ


              These show the JMS destinations starting up on your server -- thus the JMS server has failed over properly.

              Then you see entries like this:

              2006-03-13 15:24:57,756 INFO [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Reconnected to JMS pro
              vider


              These show your MDBs successfully re-connecting.

              • 4. Re: Exceptions thrown during HAJMS failover
                nealang

                Hi Brian,

                Thank you for your confirmation and support!

                You have been a great help!
                =)