Modifying LocalXAResourceImpl to return RMFAIL out of XAResource::commit() if it does not know whether the database committed or not
tomjenkinson Jan 15, 2015 5:29 AMFor background, a scenario was recently reported when using the CMR functionality of JBoss EAP which can result in unreported data integrity issues. The issue is reported here: Bug 1181132 – Data inconsistency for CMR when connection is broken after database resource commits. For those unfamiliar with the CMR algorithm, the outcome of a 1PC resource is used to dictate the outcome of the following XA resources. If the 1PC returns rollback, the other resources are rolled back, otherwise they are committed.
> Can LocalXAResource assume something about the XAException error code based on the exception caught
We have discovered that LocalXAResourceImpl (ironjacamar/LocalXAResourceImpl.java at ironjacamar-1.0.30.Final · ironjacamar/ironjacamar · GitHub) treats any failure from Connection::commit as if the connection is guaranteeing that the resource manager has rolled back. There are some scenarios where this assertion does not hold true. These scenarios are discussed in the SQL specification and covered by SQL states 8006-7 in http://pubs.opengroup.org/onlinepubs/9695959099/toc.pdf:
’08006’ — Connection failure
’08007’ — Transaction resolution unknown
> Could the JDBC resource adapter be improved to provide additional hints to the case
Consider the following:
driver.commit()
--> invoke RPC to commit remote resource manager
--> remote resource manager commits
--> connection breaks to driver before response can be returned
I am not familiar with JCA but in those scenarios it is a violation of the XA specification to return RBROLLBACK as RBROLLBACK is not ambiguous and asserts that the resource has rolled back. The correct code to return in that scenario would be RMFAIL. I have a very basic prototype that checks the SQLException from the ResourceException within the jbossts LocalXAResourceImpl:
https://github.com/tomjenkinson/ironjacamar/compare/ironjacamar:1.0...tomjenkinson:1181132?expand=1
You will see from my diff I have looked at the linked SQLException and checked if it is one of the known connection failures (after a remote call has started) from the SQL spec. You will also see that the change is localized solely in the jbossts package. That being said - I haven't actually tested it but I wanted to communicate what I think we need here for your feedback on this.
EDIT: Including the stack trace:
14:37:09,538 WARN [com.arjuna.ats.jta] (EJB default - 5) ARJUNA016036: commit on < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0a280468:35b4979e:54b3cdf0:2b, node_name=1, branch_uid=0:ffff0a280468:35b4979e:54b3cdf0:30, subordinatenodename=null, eis_name=java:jboss/xa-datasources/CrashRecoveryDS > (LocalXAResourceImpl@485b0678[connectionListener=134bf9b1 connectionManager=5005d564 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.5 jndiName=java:jboss/xa-datasources/CrashRecoveryDS]) failed with exception $XAException.XA_RBROLLBACK: org.jboss.jca.core.spi.transaction.local.LocalXAException: IJ001156: Could not commit local transaction
at org.jboss.jca.core.tx.jbossts.LocalXAResourceImpl.commit(LocalXAResourceImpl.java:180)
at com.arjuna.ats.internal.jta.resources.arjunacore.CommitMarkableResourceRecord.commit(CommitMarkableResourceRecord.java:495) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.internal.jta.resources.arjunacore.CommitMarkableResourceRecord.topLevelCommit(CommitMarkableResourceRecord.java:476) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2754) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2670) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1828) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1508) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.29.Final-redhat-1.jar:4.17.29.Final-redhat-1]
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:284) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:345) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:243) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:75) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:332) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:69) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:202) [jboss-as-ejb3-7.5.0.Final-redhat-17.jar:7.5.0.Final-redhat-17]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_71]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_71]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_71]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_71]
at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_71]
at org.jboss.threads.JBossThread.run(JBossThread.java:122)
Caused by: javax.resource.ResourceException: SQLException
at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.checkException(BaseWrapperManagedConnection.java:1202) [ironjacamar-jdbc-1.0.30.Final-redhat-1.jar:1.0.30.Final-redhat-1]
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnection.commit(LocalManagedConnection.java:99) [ironjacamar-jdbc-1.0.30.Final-redhat-1.jar:1.0.30.Final-redhat-1]
at org.jboss.jca.core.tx.jbossts.LocalXAResourceImpl.commit(LocalXAResourceImpl.java:175)
... 45 more
Caused by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:281)
at org.postgresql.jdbc2.AbstractJdbc2Connection.executeTransactionCommand(AbstractJdbc2Connection.java:814)
at org.postgresql.jdbc2.AbstractJdbc2Connection.commit(AbstractJdbc2Connection.java:838)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnection.commit(LocalManagedConnection.java:95) [ironjacamar-jdbc-1.0.30.Final-redhat-1.jar:1.0.30.Final-redhat-1]
... 46 more
Caused by: java.io.EOFException
at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:284)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
... 49 more
Message was edited by: Tom Jenkinson