Does Spring actually start a new transaction with REQUIRES_NEW?

Question

My spring (4.1.1) application is deployed on a JBoss-6.10-final instance, so it uses the container-based transaction manager and data sources. For messaging, I use TIBCO EMS 8.1 with an XA queue connection factory set up. The Java version is 1.8.0_20. All of this is running on my Ubuntu 14.04 laptop.

I need to send a request via JMS and then wait for the reply. The bean I’m calling from has transaction propagation set to Propagation.REQUIRED, so I need to send the request in a new transaction and then wait for the reply. This means the request is sent in a separate bean with transaction propagation set to Propagation.REQUIRES_NEW. It works, but I’m getting a worrisome warning from JBoss:

14-10-02 12:06:12,902 WARN [org.jboss.tm.usertx.UserTransactionRegistry] (http-0.0.0.0-8080-1) Error notifying listener org.jboss.resource.connectionmanager.CachedConnectionManager@1917b4de of userTransactionStarted: java.lang.IllegalStateException: Trying to change transaction TransactionImple < ac, BasicAction: 0:ffff7f000101:126a:542d2010:d8 status: ActionStatus.RUNNING > in enlist! at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.enlist(TxConnectionManager.java:690) at org.jboss.resource.connectionmanager.TxConnectionManager.transactionStarted(TxConnectionManager.java:427) at org.jboss.resource.connectionmanager.CachedConnectionManager.userTransactionStarted(CachedConnectionManager.java:350) at org.jboss.tm.usertx.UserTransactionRegistry.userTransactionStarted(UserTransactionRegistry.java:119) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.begin(ServerVMClientUserTransaction.java:141) at org.springframework.transaction.jta.JtaTransactionManager.doJtaBegin(JtaTransactionManager.java:875) at org.springframework.transaction.jta.JtaTransactionManager.doBegin(JtaTransactionManager.java:832) at org.springframework.transaction.support.AbstractPlatformTransactionManager.handleExistingTransaction(AbstractPlatformTransactionManager.java:425) at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:349) at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:438) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:261) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:95) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) at com.sun.proxy.$Proxy234.request(Unknown Source) at com.izazi.ioriginate.framework.spring.jms.AbstractRequestReply.request(AbstractRequestReply.java:58) at com.izazi.ioriginate.service.addressvalidation.AddressValidationServiceImpl.validate(AddressValidationServiceImpl.java:34) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:98) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:266) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:95) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) at com.sun.proxy.$Proxy235.validate(Unknown Source) at com.izazi.ioriginate.services.dwr.AddressValidation.validate(AddressValidation.java:40) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.directwebremoting.impl.ExecuteAjaxFilter.doFilter(ExecuteAjaxFilter.java:34) at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428) at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:431) at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:283) at org.directwebremoting.servlet.PlainCallHandler.handle(PlainCallHandler.java:52) at org.directwebremoting.servlet.UrlProcessor.handle(UrlProcessor.java:101) at org.directwebremoting.servlet.DwrServlet.doPost(DwrServlet.java:146) at javax.servlet.http.HttpServlet.service(HttpServlet.java:754) at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:324) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:242) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:201) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.ui.DefaultLoginPageGeneratingFilter.doFilter(DefaultLoginPageGeneratingFilter.java:155) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:274) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:242) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:181) at org.jboss.modcluster.catalina.CatalinaContext$RequestListenerValve.event(CatalinaContext.java:285) at org.jboss.modcluster.catalina.CatalinaContext$RequestListenerValve.invoke(CatalinaContext.java:261) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:88) at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:100) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:159) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158) at org.apache.catalina.valves.RequestDumperValve.invoke(RequestDumperValve.java:151) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.invoke(ActiveRequestResponseCacheValve.java:53) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:362) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:951) at java.lang.Thread.run(Thread.java:745)

...and on the EMS side, I see some XA errors:

johan@my_machine:~/opt/jboss-6.1.0.Final/bin$ 2014-10-02 10:43:15.801 ERROR: Transaction for non-existent consumer: 15 connID=16 sessID=20 {formatID=131076 gtrid_length=29 bqual_length=28 data=%00%00%00%00%00%00%00%00%00%00%FF%FF%7F%00%01%01%00%00%12jT-%0D*%00%00%00%AF1%00%00%00%00%00%00%00%00%00%00%FF%FF%7F%00%01%01%00%00%12jT-%0D*%00%00%00%B1} 2014-10-02 10:43:15.832 ERROR: Error processing xa end - transaction marked ROLLBACKONLY, Exception. connID=16 sessID=20 {formatID=131076 gtrid_length=29 bqual_length=28 data=%00%00%00%00%00%00%00%00%00%00%FF%FF%7F%00%01%01%00%00%12jT-%0D*%00%00%00%AF1%00%00%00%00%00%00%00%00%00%00%FF%FF%7F%00%01%01%00%00%12jT-%0D*%00%00%00%B1}

After looking at the stack trace, I opened the source for Spring’s AbstractPlatformTransactionManager and came across the following code for handing of REQUIRES_NEW (starting at line 415):

if (definition.getPropagationBehavior() == TransactionDefinition.PROPAGATION_REQUIRES_NEW) {
    if (debugEnabled) {
        logger.debug("Suspending current transaction, creating new transaction with name [" +
                definition.getName() + "]");
    }
    SuspendedResourcesHolder suspendedResources = suspend(transaction);
    try {
        boolean newSynchronization = (getTransactionSynchronization() != SYNCHRONIZATION_NEVER);
        DefaultTransactionStatus status = newTransactionStatus(
                definition, transaction, true, newSynchronization, debugEnabled, suspendedResources);
        doBegin(transaction, definition);
        prepareSynchronization(status, definition);
        return status;
    }
    catch (RuntimeException beginEx) {
        resumeAfterBeginException(transaction, suspendedResources, beginEx);
        throw beginEx;
    }
    catch (Error beginErr) {
        resumeAfterBeginException(transaction, suspendedResources, beginErr);
        throw beginErr;
    }
}

My question is: where is a new transaction being started?

On the surface it looks like the existing transaction is being used instead of a new one being started - see how 'transaction' is being passed to doBegin(...). I looked in doBegin as well, and there is no indication of a new transaction being requested or created. This view appears to be supported by the stack trace and warning I get from JBoss...

Answer 1

Happy to see that I'am not alone stuck in this ligthless hole...

As far as I got it, the deep cause of this warning is described here (end of the thread)

when the outer transaction is suspended and the new inner transaction started, the managed connection that Jboss connection pool retrieves for the inner transaction is the same as that of the outer transaction, which is causing the IllegalStateException to get thrown!

and is due to a specific behavior of the jboss JCA contract implementation (Lazy JCA enlistment).

A defect has been opened on spring side, flagged as "won't fix" but they provide a workaround configuration :

The typical solution is to use Spring's TransactionAwareDataSourceProxy and switch the "reobtainTransactionalConnections" flag to "true" there

Have fun !