[QPID-3658] Rolling back with ManagedConnectingMBean sometimes fails to rollback the transaction or results in various exceptions propagated into a client.

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.15
• Fix Version/s: 0.15
• Component/s: Broker-J
• Assignee: Unassigned
• Reporter: Alex Rudyy
• Created: 02/Dec/11 10:01
• Updated: 02/Dec/11 12:02
• Resolved: 02/Dec/11 12:02

Description

Tests from org.apache.qpid.management.jmx.ManagedConnectionMBeanTest added as part of introducing ManagedConnectionMBean on 0-10 path (QPID-2243) reviled several issues with transaction rollback on both 0-9 and 0-10 paths.

1) The first issue sporadically occurs for test profiles java-bdb-spawn.0-9-1, java-bdb-spawn.0-10.
Transaction can be not rolled back at all with ManagedConnectionMBean#rollback and the following commit from a client can successfully commit all published messages.
The failed test stack trace demonstrate the problem

{nowrap}
junit.framework.AssertionFailedError: Unexpected message received
at org.apache.qpid.management.jmx.ManagedConnectionMBeanTest.testRollback(ManagedConnectionMBeanTest.java:217)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:240)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:135){nowrap}

2) The second issue sporadically occurs on trying to rolled back transaction for test profile java-bdb-spawn.0-9-1
The BDB native exception is thrown on rollback from ManagedConnectionMBean

{nowrap}
org.apache.qpid.management.jmx.ManagedConnectionMBeanTest.testRollback
Error Message

Transaction Id 11 has been closed.

Stacktrace

java.lang.IllegalStateException: Transaction Id 11 has been closed.
at com.sleepycat.je.Transaction.checkOpen(Transaction.java:764)
at com.sleepycat.je.Transaction.doCommit(Transaction.java:466)
at com.sleepycat.je.Transaction.commitNoSync(Transaction.java:388)
at org.apache.qpid.server.store.berkeleydb.BDBMessageStore.commit(BDBMessageStore.java:1742)
at org.apache.qpid.server.store.berkeleydb.BDBMessageStore.commitTranImpl(BDBMessageStore.java:1281)
at org.apache.qpid.server.store.berkeleydb.BDBMessageStore.access$400(BDBMessageStore.java:94)
at org.apache.qpid.server.store.berkeleydb.BDBMessageStore$StoredBDBMessage.flushToStore(BDBMessageStore.java:2053)
at org.apache.qpid.server.store.berkeleydb.BDBMessageStore$StoredBDBMessage.remove(BDBMessageStore.java:2069)
at org.apache.qpid.server.AMQChannel$2.onRollback(AMQChannel.java:303)
at org.apache.qpid.server.txn.LocalTransaction.rollback(LocalTransaction.java:293)
at org.apache.qpid.server.AMQChannel.rollback(AMQChannel.java:989)
at org.apache.qpid.server.AMQChannel.rollback(AMQChannel.java:966)
at org.apache.qpid.server.protocol.AMQProtocolEngine.rollbackTransactions(AMQProtocolEngine.java:646)
at org.apache.qpid.server.protocol.AMQProtocolSessionMBean.rollbackTransactions(AMQProtocolSessionMBean.java:173)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:93)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:27)
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:208)
at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:120)
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:262)
at javax.management.StandardMBean.invoke(StandardMBean.java:391)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:836)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:761)
at org.apache.qpid.server.management.MBeanInvocationHandlerImpl.invoke(MBeanInvocationHandlerImpl.java:202)
at $Proxy11.invoke(Unknown Source)
at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1427)
at javax.management.remote.rmi.RMIConnectionImpl.access$200(RMIConnectionImpl.java:72)
at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1265)
at java.security.AccessController.doPrivileged(Native Method)
at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1367)
at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:788)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)
at sun.rmi.transport.Transport$1.run(Transport.java:159)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:155)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
{nowrap}

3) The third issue sporadically happens for 0-10 bdb profile on trying to receive a message in a separate session after transaction was previously rolled back with MBean.
The stack trace is below

{nowrap}
Error Message

Message consumer forcibly closed due to error: org.apache.qpid.AMQException: ch=1 id=0 ExecutionException(errorCode=INTERNAL_ERROR, commandId=3, description=Exception processing command: java.lang.RuntimeException: java.lang.IllegalArgumentException: Transaction 12 has been closed and is no longer usable.) [error code 541: internal error]

Stacktrace

javax.jms.JMSException: Message consumer forcibly closed due to error: org.apache.qpid.AMQException: ch=1 id=0 ExecutionException(errorCode=INTERNAL_ERROR, commandId=3, description=Exception processing command: java.lang.RuntimeException: java.lang.IllegalArgumentException: Transaction 12 has been closed and is no longer usable.) [error code 541: internal error]
at org.apache.qpid.client.BasicMessageConsumer.returnMessageOrThrow(BasicMessageConsumer.java:529)
at org.apache.qpid.client.BasicMessageConsumer.receive(BasicMessageConsumer.java:417)
at org.apache.qpid.management.jmx.ManagedConnectionMBeanTest.testRollback(ManagedConnectionMBeanTest.java:210)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:240)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:135)
Caused by: org.apache.qpid.AMQException: ch=1 id=0 ExecutionException(errorCode=INTERNAL_ERROR, commandId=3, description=Exception processing command: java.lang.RuntimeException: java.lang.IllegalArgumentException: Transaction 12 has been closed and is no longer usable.) [error code 541: internal error]
at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1056)
at org.apache.qpid.client.AMQSession_0_10.exception(AMQSession_0_10.java:914)
at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:160)
at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:32)
at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:112)
at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50)
at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:32)
at org.apache.qpid.transport.Method.delegate(Method.java:159)
at org.apache.qpid.transport.Session.received(Session.java:545)
at org.apache.qpid.transport.Connection.dispatch(Connection.java:422)
at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64)
at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40)
at org.apache.qpid.transport.MethodDelegate.executionException(MethodDelegate.java:110)
at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:112)
at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54)
at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40)
at org.apache.qpid.transport.Method.delegate(Method.java:159)
at org.apache.qpid.transport.Connection.received(Connection.java:387)
at org.apache.qpid.transport.Connection.received(Connection.java:66)
at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:95)
at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:196)
at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:129)
at org.apache.qpid.transport.network.Frame.delegate(Frame.java:133)
at org.apache.qpid.transport.network.Assembler.received(Assembler.java:100)
at org.apache.qpid.transport.network.Assembler.received(Assembler.java:42)
at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:187)
at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:103)
at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:42)
at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:153)
at java.lang.Thread.run(Thread.java:662){nowrap}