In last resource commit optimization, commit call to the last resource isn't invoked last which leads to inconsistent result
lily.he Jun 17, 2014 9:20 AMWe have a xa recovery test case as following:
1. Deploy our jms RA to jboss which communicates to weblogic server.
2. Start one transaction which includes msg sending via the RA to Weblogic server and some DB operations, so two RMs involved.
3. From jboss log we found DB operations is wrapped by class com.arjuna.ats.internal.arjuna.abstractrecords.LastResourceRecord. LastResourceRecord is used to do the last resource commit optimization.
4. In our case, weblogic server will shutdown during the prepare call and result in prepare call failed.
5. From server log, we find jboss TM call DB prepare first and then call weblogic prepare. And DB prepare is optimized as commit call. Then weblogic prepare call failed and then TM try to rollback the transaction. But will got following exception when try to call DB rollback since the transaction in DB has been committed.
Daemon Thread [http--0.0.0.0-8080-2] (Suspended (breakpoint at line 98 in org.jboss.jca.core.tx.jbossts.LocalXAResourceImpl))
org.jboss.jca.core.tx.jbossts.LocalXAResourceImpl.start(javax.transaction.xa.Xid, int) line: 98
com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(javax.transaction.xa.XAResource, java.lang.Object[]) line: 636
com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(javax.transaction.xa.XAResource) line: 397
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.enlist() line: 587
org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist() line: 264
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(org.jboss.jca.core.connectionmanager.listener.ConnectionListener) line: 467
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl(org.jboss.jca.core.connectionmanager.AbstractConnectionManager).reconnectManagedConnection(org.jboss.jca.core.connectionmanager.listener.ConnectionListener) line: 599
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl(org.jboss.jca.core.connectionmanager.AbstractConnectionManager).allocateConnection(javax.resource.spi.ManagedConnectionFactory, javax.resource.spi.ConnectionRequestInfo) line: 467
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection() line: 129
wlstest.functional.jms.wlsra.common.utils.JMSRAServerUtil.getConnection(javax.naming.Context, java.lang.String) line: 952
wlstest.functional.jms.wlsra.common.utils.JMSRAServerUtil.incrementCounter(javax.naming.Context, java.lang.String, java.lang.String, java.lang.String, java.lang.String) line: 1003
wlstest.functional.jms.wlsra.JmsraCactusNonGFTest.doTxRecoveryWLSRestartITMInstrumentation(int, java.lang.String, java.lang.String) line: 968
wlstest.functional.jms.wlsra.JmsraCactusNonGFTest.testTxRecoveryWLSRestartBeforePrepare() line: 739
sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) line: not available [native method]
sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) line: 57
sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) line: 43
java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object...) line: 606
wlstest.functional.jms.wlsra.JmsraCactusNonGFTest(junit.framework.TestCase).runTest() line: 154
wlstest.functional.jms.wlsra.JmsraCactusNonGFTest(junit.framework.TestCase).runBare() line: 127
org.apache.cactus.internal.server.ServletTestCaller(org.apache.cactus.internal.server.AbstractWebTestCaller).doTest() line: 124
org.apache.cactus.internal.server.AbstractWebTestController.handleRequest_aroundBody0(org.apache.cactus.internal.server.AbstractWebTestController, org.apache.cactus.spi.server.ImplicitObjects, org.aspectj.lang.JoinPoint) line: 93
org.apache.cactus.internal.server.AbstractWebTestController.handleRequest_aroundBody1$advice(org.apache.cactus.internal.server.AbstractWebTestController, org.apache.cactus.spi.server.ImplicitObjects, org.aspectj.lang.JoinPoint, org.apache.cactus.util.log.LogAspect, org.aspectj.runtime.internal.AroundClosure, org.aspectj.lang.JoinPoint) line: 224
org.apache.cactus.internal.server.ServletTestController(org.apache.cactus.internal.server.AbstractWebTestController).handleRequest(org.apache.cactus.spi.server.ImplicitObjects) line: 1
org.apache.cactus.server.ServletTestRedirector.doPost_aroundBody2(org.apache.cactus.server.ServletTestRedirector, javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, org.aspectj.lang.JoinPoint) line: 101
org.apache.cactus.server.ServletTestRedirector.doPost_aroundBody3$advice(org.apache.cactus.server.ServletTestRedirector, javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, org.aspectj.lang.JoinPoint, org.apache.cactus.util.log.LogAspect, org.aspectj.runtime.internal.AroundClosure, org.aspectj.lang.JoinPoint) line: 224
org.apache.cactus.server.ServletTestRedirector.doPost(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) line: 1
org.apache.cactus.server.ServletTestRedirector.doGet_aroundBody0(org.apache.cactus.server.ServletTestRedirector, javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, org.aspectj.lang.JoinPoint) line: 72
org.apache.cactus.server.ServletTestRedirector.doGet_aroundBody1$advice(org.apache.cactus.server.ServletTestRedirector, javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, org.aspectj.lang.JoinPoint, org.apache.cactus.util.log.LogAspect, org.aspectj.runtime.internal.AroundClosure, org.aspectj.lang.JoinPoint) line: 224
org.apache.cactus.server.ServletTestRedirector.doGet(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) line: 1
org.apache.cactus.server.ServletTestRedirector(javax.servlet.http.HttpServlet).service(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) line: 734
org.apache.cactus.server.ServletTestRedirector(javax.servlet.http.HttpServlet).service(javax.servlet.ServletRequest, javax.servlet.ServletResponse) line: 847
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) line: 329
org.apache.catalina.core.ApplicationFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) line: 248
org.testlogic.testrunner.ant.cactus.CactusRemoteParamFilter.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse, javax.servlet.FilterChain) line: 52
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) line: 280
org.apache.catalina.core.ApplicationFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) line: 248
org.apache.catalina.core.StandardWrapperValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 275
org.apache.catalina.core.StandardContextValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 161
org.apache.catalina.authenticator.BasicAuthenticator(org.apache.catalina.authenticator.AuthenticatorBase).invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 397
org.jboss.as.web.security.SecurityContextAssociationValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 153
org.apache.catalina.core.StandardHostValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 155
org.apache.catalina.valves.ErrorReportValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 102
org.apache.catalina.core.StandardEngineValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) line: 109
org.apache.catalina.connector.CoyoteAdapter.service(org.apache.coyote.Request, org.apache.coyote.Response) line: 368
org.apache.coyote.http11.Http11Processor.process(java.net.Socket) line: 877
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(java.net.Socket) line: 671
org.apache.tomcat.util.net.JIoEndpoint$Worker.run() line: 930
java.lang.Thread.run() line: 744
Pls check attached jboss log file.
two XAResource enlist in one transaction: XAResourceWrapperImpl which represents weblogic opts and LocalXAResourceImpl which represents DB opts
20:17:13,516 TRACE [com.arjuna.ats.jta] (http--0.0.0.0-8080-2) TransactionImple.enlistResource ( XAResourceWrapperImpl@39ce8088[xaResource=weblogic.jms.ra.XAResourceWrapper@24587e5e pad=false overrideRmValue=false productName=java:jboss/wljmsra/clusterXAQCF productVersion=java:jboss/wljmsra/clusterXAQCF jndiName=java:jboss/wljmsra/clusterXAQCF] )
20:17:14,729 TRACE [com.arjuna.ats.jta] (http--0.0.0.0-8080-2) TransactionImple.enlistResource ( LocalXAResourceImpl@2f1b7528[connectionListener=634defe1 connectionManager=1c565475 warned=false currentXid=null] )
XAResource prepare sequence: first LastResourceRecord which contains LocalXAResourceImpl and then XAResourceRecord which contains XAResourceWrapperImpl
20:17:45,008 TRACE [com.arjuna.ats.arjuna] (http--0.0.0.0-8080-2) LastResourceRecord::topLevelPrepare() for 0:0:0:0:1
20:17:45,013 TRACE [com.arjuna.ats.jta] (http--0.0.0.0-8080-2) XAResourceRecord.topLevelPrepare for XAResourceRecord < resource:XAResourceWrapperImpl@39ce8088[xaResource=weblogic.jms.ra.XAResourceWrapper@24587e5e pad=false overrideRmValue=false productName=java:jboss/wljmsra/clusterXAQCF productVersion=java:jboss/wljmsra/clusterXAQCF jndiName=java:jboss/wljmsra/clusterXAQCF], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0af51e58:-79602179:539e611b:b, node_name=1, branch_uid=0:ffff0af51e58:-79602179:539e611b:10, subordinatenodename=null, eis_name=java:jboss/wljmsra/clusterXAQCF >, heuristic: TwoPhaseOutcome.FINISH_OK, product: java:jboss/wljmsra/clusterXAQCF/java:jboss/wljmsra/clusterXAQCF, jndiName: java:jboss/wljmsra/clusterXAQCF com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@1826b48 >