HA-JMS MDBs doesn't recover on slave when master failed.?
tomdee Oct 21, 2005 12:57 AMOS: Win2K
DB: Oracle 9i
JBoss: 3.2.6, 3.2.7, 4.0.3
Test Case
=======
1. Run 2 servers in HA mode, Server A is master, B Slave
2. Deploy MDBs which do nothing other than a sleep() + System.out. MDBs use CMT with trans-attribute=REQUIRED.
3. Submit messages to JMS (using AUTO_ACKNOWLEDGE) , and observe that MDBs on both Server A and B are processing the msgs.
4. While B (Slave) is processing, shut down A to simulate a master failure.
5. Observed that B makes the transition to Master status.
6a. However, when the MDB on B wakes up from the sleep, a number of exeption is thrown in B's console indicating failure to commit/rollback.
6b. B is now stuck in this perpetual pattern of trying to commit but failed (looks like it's still trying to connect to the old master instead of itself who is now the new master?)
This only happens if the master goes away while the slave is processing. The reverse case where the slave goes away functions as expected.
2005-10-20 23:38:52,860 ERROR [org.jboss.jms.asf.StdServerSession] failed to commit/rollback org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=QAAPP08/1376, BranchQual=, localId=1376] status=STATUS_NO_TRANSACTION; - nested throwable: (org.jboss.mq.SpyXAException: - nested throwable: (org.jboss.mq.SpyTransactionRolledBackException: Transaction was rolled back.; - nested throwable: (javax.jms.JMSException: The provided subscription does not exist))) at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:354) at org.jboss.tm.TxManager.commit(TxManager.java:224) at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:341) at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:904) at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:160) at org.jboss.mq.SpySession.run(SpySession.java:333) at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180) at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748) at java.lang.Thread.run(Thread.java:595) Caused by: org.jboss.mq.SpyXAException: - nested throwable: (org.jboss.mq.SpyTransactionRolledBackException: Transaction was rolled back.; - nested throwable: (javax.jms.JMSException: The provided subscription does not exist)) at org.jboss.mq.SpyXAResource.commit(SpyXAResource.java:87) at org.jboss.tm.TransactionImpl$Resource.commit(TransactionImpl.java:2233) at org.jboss.tm.TransactionImpl.commitResources(TransactionImpl.java:1764) at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:322) ... 8 more Caused by: org.jboss.mq.SpyTransactionRolledBackException: Transaction was rolled back.; - nested throwable: (javax.jms.JMSException: The provided subscription does not exist) at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:442) at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:186) at org.jboss.mq.il.uil2.ServerSocketManagerHandler.handleMsg(ServerSocketManagerHandler.java:172) at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleMsg(SocketManager.java:369) at org.jboss.mq.il.uil2.msgs.BaseMsg.run(BaseMsg.java:377) ... 2 more Caused by: javax.jms.JMSException: The provided subscription does not exist at org.jboss.mq.server.ClientConsumer.acknowledge(ClientConsumer.java:321) at org.jboss.mq.server.JMSDestinationManager.acknowledge(JMSDestinationManager.java:519) at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:431) ... 6 more 2005-10-20 23:38:53,157 INFO [org.jboss.ha.framework.interfaces.HAPartition.lifecycle.CLUSTER_TEST] New cluster view for partition CLUSTER_TEST (id: 2, delta: -1) : [192.168.10.46:1099] 2005-10-20 23:38:53,157 INFO [org.jboss.ha.framework.server.DistributedReplicantManagerImpl.CLUSTER_TEST] I am (192.168.10.46:1099) received membershipChanged event: 2005-10-20 23:38:53,157 INFO [org.jboss.ha.framework.server.DistributedReplicantManagerImpl.CLUSTER_TEST] Dead members: 1 ([192.168.10.45:1099]) 2005-10-20 23:38:53,157 INFO [org.jboss.ha.framework.server.DistributedReplicantManagerImpl.CLUSTER_TEST] New Members : 0 ([]) 2005-10-20 23:38:53,157 INFO [org.jboss.ha.framework.server.DistributedReplicantManagerImpl.CLUSTER_TEST] All Members : 1 ([192.168.10.46:1099]) 2005-10-20 23:38:54,641 INFO [org.jboss.mq.il.uil2.UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093 2005-10-20 23:38:54,735 INFO [org.jboss.mq.server.jmx.Queue.DLQ] Bound to JNDI name: queue/DLQ 2005-10-20 23:39:03,703 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:595) Caused by: java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:168) at java.io.BufferedInputStream.fill(BufferedInputStream.java:218) at java.io.BufferedInputStream.read(BufferedInputStream.java:235) at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67) at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2200) at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2380) at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2447) at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2519) at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2668) at java.io.ObjectInputStream.readByte(ObjectInputStream.java:864) at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290) ... 1 more 2005-10-20 23:39:03,719 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:595) Caused by: java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:168) at java.io.BufferedInputStream.fill(BufferedInputStream.java:218) at java.io.BufferedInputStream.read(BufferedInputStream.java:235) at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67) at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2200) at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2380) at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2447) at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2519) at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2668) at java.io.ObjectInputStream.readByte(ObjectInputStream.java:864) at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290) ... 1 more 2005-10-20 23:39:08,781 INFO [org.jboss.mq.server.jmx.Queue.testQueue] Bound to JNDI name: queue/testQueue 2005-10-20 23:39:26,843 WARN [org.jboss.mq.Connection] Connection failure, use javax.jms.Connection.setExceptionListener() to handle this error and reconnect 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:470) at org.jboss.mq.Connection.pingServer(Connection.java:883) ... 3 more 2005-10-20 23:39:26,874 WARN [org.jboss.ejb.plugins.jms.JMSContainerInvoker] JMS provider failure detected: 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:470) at org.jboss.mq.Connection.pingServer(Connection.java:883)