Provide ability to eject connections on rollback failure

I'm not sure if this is a bug in BTM, or a bug in Derby that needs to be worked around.

Our product is getting into the situation at a customer site where it becomes unusable.

This is an exception we are seeing in the logs. Note the exception messages from Derby were in Japanese, I ran them through a translator; they are fairly understandable.

10-10-22 11:50:32,305 [TransactionElf ] [Jetty-43 ] WARN - Transaction commit failed.
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:179)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1206)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:375)
at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:88)
at bitronix.tm.BitronixTransaction.fireBeforeCompletionEvent(BitronixTransaction.java:430)
at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:173)
at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:104)
at org.ziptie.zap.jta.TransactionElf.commit(TransactionElf.java:68)
at org.ziptie.server.web.ZTransactionFilter.doFilter(ZTransactionFilter.java:86)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.server.security.ZSecurityFilter.doFilter(ZSecurityFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.zap.metro.ZThreadContextFilter.doFilter(ZThreadContextFilter.java:49)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.ziptie.zap.web.internal.ZContext.handle(ZContext.java:148)
at org.ziptie.zap.web.ZSessionHandler.handle(ZSessionHandler.java:108)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:938)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
Caused by: org.apache.derby.client.am.BatchUpdateException: Non-atomic batch failed. The batch has been submitted, at least one exception occurred in one batch of individual members. To get an exception in a particular batch processed elements please use getNextException ().
at org.apache.derby.client.am.Agent.endBatchedReadChain(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.executeBatchRequestX(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.executeBatchX(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.executeBatch(Unknown Source)
at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:44)
at $Proxy55.executeBatch(Unknown Source)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
... 34 more
Caused by: org.apache.derby.client.am.SqlException: Batch element #0 Error: This statement is a unique or primary key constraint, or the 'DEVICE' defined on 'UNIQUE_DEVICE' because that could cause duplicate key value in a unique index identified by aborted.
at org.apache.derby.client.am.Statement.completeExecute(Unknown Source)
at org.apache.derby.client.net.NetStatementReply.parseEXCSQLSTTreply(Unknown Source)
at org.apache.derby.client.net.NetStatementReply.readExecute(Unknown Source)
at org.apache.derby.client.net.StatementReply.readExecute(Unknown Source)
at org.apache.derby.client.net.NetPreparedStatement.readExecute_(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.readExecute(Unknown Source)
... 44 more
10-10-22 11:50:32,446 [log ] [Jetty-43 ] ERROR - /server/devices
java.lang.RuntimeException: Transaction commit failed.
at org.ziptie.zap.jta.TransactionElf.commit(TransactionElf.java:74)
at org.ziptie.server.web.ZTransactionFilter.doFilter(ZTransactionFilter.java:86)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.server.security.ZSecurityFilter.doFilter(ZSecurityFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.zap.metro.ZThreadContextFilter.doFilter(ZThreadContextFilter.java:49)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.ziptie.zap.web.internal.ZContext.handle(ZContext.java:148)
at org.ziptie.zap.web.ZSessionHandler.handle(ZSessionHandler.java:108)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:938)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
Caused by: org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:179)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1206)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:375)
at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:88)
at bitronix.tm.BitronixTransaction.fireBeforeCompletionEvent(BitronixTransaction.java:430)
at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:173)
at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:104)
at org.ziptie.zap.jta.TransactionElf.commit(TransactionElf.java:68)
... 23 more
Caused by: org.apache.derby.client.am.BatchUpdateException: Non-atomic batch failed. The batch has been submitted, at least one exception occurred in one batch of individual members. To get an exception in a particular batch processed elements please use getNextException ().
at org.apache.derby.client.am.Agent.endBatchedReadChain(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.executeBatchRequestX(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.executeBatchX(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.executeBatch(Unknown Source)
at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:44)
at $Proxy55.executeBatch(Unknown Source)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
... 34 more
Caused by: org.apache.derby.client.am.SqlException: Batch element #0 Error: This statement is a unique or primary key constraint, or the 'DEVICE' defined on 'UNIQUE_DEVICE' because that could cause duplicate key value in a unique index identified by aborted.
at org.apache.derby.client.am.Statement.completeExecute(Unknown Source)
at org.apache.derby.client.net.NetStatementReply.parseEXCSQLSTTreply(Unknown Source)
at org.apache.derby.client.net.NetStatementReply.readExecute(Unknown Source)
at org.apache.derby.client.net.StatementReply.readExecute(Unknown Source)
at org.apache.derby.client.net.NetPreparedStatement.readExecute_(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.readExecute(Unknown Source)
... 44 more

It appears that under some condition, not reproducible in our testing, an insert action that results in a duplicate primary key exception occurs. Derby (I think) unilaterally rollback back the transaction and (in some cases) closes the connection. It is this latter action that seems to cause the problem.

The connection with the failed transaction remains in the Bitronix. Subsequent callers to the server are issued this same connection. The server has a servlet filter that performs a begin/end transaction on every client call. Threads calling into the server, and performing SQL are met with these exceptions:

10-10-22 11:52:31,869 [BitronixTransaction ] [Jetty-46 ] ERROR - error delisting resource: an XAResourceHolderState with uniqueName=ziptie-ds XAResource=org.apache.derby.client.net.NetXAResource@b3d7ef (started) with XID a Bitronix XID [6E65746C642D310000012BD1D92A5E0000B473 : 6E65746C642D310000012BD1D92A5E0000B475]
bitronix.tm.internal.BitronixSystemException: cannot delist an XAResourceHolderState with uniqueName=ziptie-ds XAResource=org.apache.derby.client.net.NetXAResource@b3d7ef (started) with XID a Bitronix XID [6E65746C642D310000012BD1D92A5E0000B473 : 6E65746C642D310000012BD1D92A5E0000B475], error=XAER_RMFAIL
at bitronix.tm.BitronixTransaction.delistResource(BitronixTransaction.java:143)
at bitronix.tm.BitronixTransaction.delistUnclosedResources(BitronixTransaction.java:372)
at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:190)
at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:104)
at org.ziptie.zap.jta.TransactionElf.commit(TransactionElf.java:68)
at org.ziptie.server.web.ZTransactionFilter.doFilter(ZTransactionFilter.java:86)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.server.security.ZSecurityFilter.doFilter(ZSecurityFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.zap.metro.ZThreadContextFilter.doFilter(ZThreadContextFilter.java:49)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.ziptie.zap.web.internal.ZContext.handle(ZContext.java:148)
at org.ziptie.zap.web.ZSessionHandler.handle(ZSessionHandler.java:108)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:938)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
Caused by: org.apache.derby.client.am.XaException: XAER_RMFAIL : Connection is Closed.
at org.apache.derby.client.net.NetXAResource.throwXAException(Unknown Source)
at org.apache.derby.client.net.NetXAResource.throwXAException(Unknown Source)
at org.apache.derby.client.net.NetXAResource.connectionClosedFailure(Unknown Source)
at org.apache.derby.client.net.NetXAResource.end(Unknown Source)
at bitronix.tm.internal.XAResourceHolderState.end(XAResourceHolderState.java:143)
at bitronix.tm.internal.XAResourceManager.delist(XAResourceManager.java:111)
at bitronix.tm.BitronixTransaction.delistResource(BitronixTransaction.java:129)
... 27 more
Caused by: org.apache.derby.client.am.SqlException: Connection is Closed.
... 32 more
10-10-22 11:52:31,884 [Rollbacker ] [Jetty-46 ] WARN - resource 'ziptie-ds' reported XAER_RMFAIL when asked to rollback transaction branch. Transaction is prepared and will rollback via recovery service when resource availability allows.
org.apache.derby.client.am.XaException: XAER_RMFAIL : Connection is Closed.
at org.apache.derby.client.net.NetXAResource.throwXAException(Unknown Source)
at org.apache.derby.client.net.NetXAResource.throwXAException(Unknown Source)
at org.apache.derby.client.net.NetXAResource.connectionClosedFailure(Unknown Source)
at org.apache.derby.client.net.NetXAResource.rollback(Unknown Source)
at bitronix.tm.twopc.Rollbacker$RollbackJob.rollbackResource(Rollbacker.java:158)
at bitronix.tm.twopc.Rollbacker$RollbackJob.execute(Rollbacker.java:147)
at bitronix.tm.twopc.executor.Job.run(Job.java:51)
at bitronix.tm.twopc.executor.SyncExecutor.submit(SyncExecutor.java:12)
at bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:110)
at bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:71)
at bitronix.tm.twopc.Rollbacker.rollback(Rollbacker.java:55)
at bitronix.tm.BitronixTransaction.rollbackPrepareFailure(BitronixTransaction.java:398)
at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:192)
at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:104)
at org.ziptie.zap.jta.TransactionElf.commit(TransactionElf.java:68)
at org.ziptie.server.web.ZTransactionFilter.doFilter(ZTransactionFilter.java:86)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.server.security.ZSecurityFilter.doFilter(ZSecurityFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.zap.metro.ZThreadContextFilter.doFilter(ZThreadContextFilter.java:49)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.ziptie.zap.web.internal.ZContext.handle(ZContext.java:148)
at org.ziptie.zap.web.ZSessionHandler.handle(ZSessionHandler.java:108)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:938)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
Caused by: org.apache.derby.client.am.SqlException: Connection is Closed.
... 36 more
10-10-22 11:52:31,978 [TransactionElf ] [Jetty-46 ] WARN - Transaction commit failed.
bitronix.tm.internal.BitronixRollbackException: unilateral resource rollback caused transaction rollback
at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:193)
at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:104)
at org.ziptie.zap.jta.TransactionElf.commit(TransactionElf.java:68)
at org.ziptie.server.web.ZTransactionFilter.doFilter(ZTransactionFilter.java:86)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.server.security.ZSecurityFilter.doFilter(ZSecurityFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.ziptie.zap.metro.ZThreadContextFilter.doFilter(ZThreadContextFilter.java:49)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.ziptie.zap.web.internal.ZContext.handle(ZContext.java:148)
at org.ziptie.zap.web.ZSessionHandler.handle(ZSessionHandler.java:108)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:938)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
Caused by: bitronix.tm.internal.BitronixRollbackException: resource(s) [ziptie-ds] unilaterally rolled back
at bitronix.tm.BitronixTransaction.delistUnclosedResources(BitronixTransaction.java:386)
at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:190)
... 25 more

It seems the resource is unable to be delisted due to an exception thrown by derby (XAER_RMFAIL : Connection is Closed). The Rollbacker is met with a similar exception.

Is there anything BTM can do to recover from this condition?

BTM says "Transaction is prepared and will rollback via recovery service when resource availability allows." However, in this case "resource availability" will NEVER allow it because the connection on which rollback is attempted no longer exists!