3 Replies Latest reply on Sep 28, 2018 10:13 AM by tomjenkinson

    Possibly unneccessary logging on XA endAssociation with DB2

    csvedin

      I'm running wildfly 13 (narayana 5.8.1.Final) with a DB2 database using XA datasource.

       

      Whenever I do setRollbackOnly(true) in a CMT ejb I get WARN logging (full log at bottom of post).

      2018-09-27 16:14:54,439 WARN  [com.arjuna.ats.jta:1104 doEnd] (default task-1) ARJUNA016129: Could not end XA resource XAResourceWrapperImpl@61bf3c2d[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@4f2c58cc pad=false overrideRmValue=false productName=DB2/LINUXX8664 productVersion=SQL11010 jndiName=java:/iipax.db]: com.ibm.db2.jcc.am.XaException: [jcc][t4][10401][12066][3.72.44] XA exception: XA_RBROLLBACK ERRORCODE=-4228, SQLSTATE=null

       

      Although it seems that the rollback works as expected anyway.

       

      I tracked the log-call down to com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.doEnd(Xid, XAResource, int, int)

      This method was added in the commit fcfb851072ea28c80902710e1179fbb9f62b3ca3 where the logic moved from XaResourceRecord to TransactionImple, at the same time the logging was introduced as far as I can tell.

       

      So my question is if this logging really is unneccessary in this case, or if something is actually wrong with my application or configuration.

       

      My datasource configuration:

       

      <xa-datasource jndi-name="java:/iipax.db" pool-name="iipax.db">

          <xa-datasource-property name="DriverType">4</xa-datasource-property>

          <xa-datasource-property name="PortNumber">3708</xa-datasource-property>

          <xa-datasource-property name="DatabaseName">*****</xa-datasource-property>

          <xa-datasource-property name="ServerName">*****</xa-datasource-property>

          <xa-datasource-property name="resultSetHoldability">1</xa-datasource-property>

          <xa-datasource-property name="downgradeHoldCursorsUnderXa">true</xa-datasource-property>

       

          <driver>db2</driver>

          <xa-pool>

              <is-same-rm-override>false</is-same-rm-override>

              <min-pool-size>10</min-pool-size>

              <max-pool-size>300</max-pool-size>

          </xa-pool>

          <security>

              <user-name>iipax</user-name>

              <password>${VAULT::vb::database_user_password::1}</password>

          </security>

          <validation>

              <valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.db2.DB2ValidConnectionChecker"/>

              <validate-on-match>true</validate-on-match>

              <background-validation>false</background-validation>

              <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.db2.DB2ExceptionSorter"/>

          </validation>

          <timeout>

              <blocking-timeout-millis>300000</blocking-timeout-millis>

          </timeout>

      </xa-datasource>

       

       

      The complete stacktrace

      2018-09-27 16:14:54,439 WARN  [com.arjuna.ats.jta:1104 doEnd] (default task-1) ARJUNA016129: Could not end XA resource XAResourceWrapperImpl@61bf3c2d[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@4f2c58cc pad=false overrideRmValue=false productName=DB2/LINUXX8664 productVersion=SQL11010 jndiName=java:/iipax.db]: com.ibm.db2.jcc.am.XaException: [jcc][t4][10401][12066][3.72.44] XA exception: XA_RBROLLBACK ERRORCODE=-4228, SQLSTATE=null
          at com.ibm.db2.jcc.am.b1.c(b1.java:565)
          at com.ibm.db2.jcc.am.b1.c(b1.java:594)
          at com.ibm.db2.jcc.t4.a4.a(a4.java:2105)
          at com.ibm.db2.jcc.t4.a4.end(a4.java:680)
          at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:299)
          at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.end(XAResourceWrapperImpl.java:118)
          at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.doEnd(TransactionImple.java:1090) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.endAssociation(TransactionImple.java:1061) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.endAssociation(XAResourceRecord.java:1286) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:313) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3023) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3002) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1674) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:124) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.arjuna.AtomicAction.abort(AtomicAction.java:186) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.rollbackAndDisassociate(TransactionImple.java:1372) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.rollback(BaseTransaction.java:143) [narayana-jts-idlj-5.8.1.Final.jar:5.8.1.Final (revision: f86d4)]
          at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.rollback(BaseTransactionManagerDelegate.java:134)
          at org.wildfly.transaction.client.LocalTransaction.rollbackAndDissociate(LocalTransaction.java:111) [wildfly-transaction-client-1.1.2.Final.jar:1.1.2.Final]
          at org.wildfly.transaction.client.ContextTransactionManager.rollback(ContextTransactionManager.java:83) [wildfly-transaction-client-1.1.2.Final.jar:1.1.2.Final]
          at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:90) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:122) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:256) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:362) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
          at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81) [weld-ejb-3.0.4.Final.jar:3.0.4.Final]
          at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.security.AuthorizationInterceptor.processInvocation(AuthorizationInterceptor.java:138) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$2.processInvocation(EjbExceptionTransformingInterceptorFactories.java:108) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) [wildfly-ejb3-13.0.0.Final.jar:13.0.0.Final]
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
          at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619) [wildfly-elytron-1.3.3.Final.jar:1.3.3.Final]
          at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
          at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
          at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
          at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
          at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
          at iipax.service.casekernel.client.iface.CaseFacadeLocal$$$view95.closeCase(Unknown Source) [casekernel.jar:]
          at iipax.service.casekernel.test.TestConfigUtil.removeTestTypesAndObjects(TestConfigUtil.java:276)
          at iipax.service.casekernel.test.TestConfigUtil.setUpTestSecurityAndConfig(TestConfigUtil.java:178)
          at iipax.service.casekernel.test.AbstractCaseEnterpriseTest.eeSetUpNoTran(AbstractCaseEnterpriseTest.java:96)
          at iipax.embedded.junit.EnterpriseTest.setUp(EnterpriseTest.java:61)
          at junit.framework.TestCase.runBare(TestCase.java:125)
          at org.apache.cactus.internal.AbstractCactusTestCase.runBareServer(AbstractCactusTestCase.java:155)
          at org.apache.cactus.internal.server.AbstractWebTestCaller.doTest(AbstractWebTestCaller.java:120)
          at org.apache.cactus.internal.server.AbstractWebTestController.handleRequest_aroundBody0(AbstractWebTestController.java:94)
          at org.apache.cactus.internal.server.AbstractWebTestController.handleRequest_aroundBody1$advice(AbstractWebTestController.java:225)
          at org.apache.cactus.internal.server.AbstractWebTestController.handleRequest(AbstractWebTestController.java:1)
          at org.apache.cactus.server.ServletTestRedirector.doPost_aroundBody2(ServletTestRedirector.java:102)
          at org.apache.cactus.server.ServletTestRedirector.doPost_aroundBody3$advice(ServletTestRedirector.java:225)
          at org.apache.cactus.server.ServletTestRedirector.doPost(ServletTestRedirector.java:1)
          at org.apache.cactus.server.ServletTestRedirector.doGet_aroundBody0(ServletTestRedirector.java:73)
          at org.apache.cactus.server.ServletTestRedirector.doGet_aroundBody1$advice(ServletTestRedirector.java:225)
          at org.apache.cactus.server.ServletTestRedirector.doGet(ServletTestRedirector.java:1)
          at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) [jboss-servlet-api_3.1_spec-1.0.2.Final.jar:1.0.2.Final]
          at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [jboss-servlet-api_3.1_spec-1.0.2.Final.jar:1.0.2.Final]
          at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
          at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
          at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
          at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
          at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
          at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
          at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
          at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
          at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
          at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:53)
          at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
          at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
          at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:59)
          at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
          at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
          at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
          at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
          at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
          at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
          at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
          at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
          at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
          at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
          at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
          at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
          at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
          at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
          at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
          at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
          at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
          at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
          at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
          at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
          at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
          at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
          at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
          at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
          at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
          at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
          at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
          at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
          at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
          at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_181]