Changing state of trackByTx during a global transaction.

[whitingjr]

Hi,

I have a query about when the state of TxConnectionListener.trackByTx should be true and false.

My JEE application uses EJB3 and JPA API with Hibernate behind the scenes. The default for JBoss EAP. So, typically during a tx the ORM framework will be putting reads and writes into an action queue. Sometimes these are flushed to the datastore, other times they remain in the queue and are flushed at the end of the transaction and flushed by a TransactionSynchronization. The application uses the default configuration for trackByTx which is true. Also nothing is configured for interleaving. Which is false by default. Plus I use postgres and the pgjdbc driver.

Some tracing has shown the connection listener at the beginning of the transaction has the state set to true. Then later on when the same associated connection listener is used again the state is false.

My question is when the connection listener is leased to the persistence layer should the state of the trackByTx field be set to true during the lifetime of a transaction ?

To help diagnose the context are attached are some logs that show the state of trackByTx changes when the connection listener is in use. Along with dumped state using Byteman. I used a bmt script to create a message and dump the stack if the state is false when TxConnectionListener.enlist is called.

Here is an extract from the log file.

12:46:50,181 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (http-f19lite/192.168.0.3:8080-19) supplying ManagedConnection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@528106c0[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@14e25191 connection handles=0 lastUse=1385556409340 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@2e0ba62b pool internal context=SemaphoreArrayListManagedConnectionPool@2d517aa8[pool=acmeOrderDS] xaResource=XAResourceWrapperImpl@317ee1b1[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@14e25191 pad=false overrideRmValue=null productName=PostgreSQL productVersion=9.2.5 jndiName=java:/jdbc/acmeOrderDS] txSync=null]

12:46:50,181 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (http-f19lite/192.168.0.3:8080-19) Got connection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@528106c0[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@14e25191 connection handles=0 lastUse=1385556409340 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@2e0ba62b pool internal context=SemaphoreArrayListManagedConnectionPool@2d517aa8[pool=acmeOrderDS] xaResource=XAResourceWrapperImpl@317ee1b1[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@14e25191 pad=false overrideRmValue=null productName=PostgreSQL productVersion=9.2.5 jndiName=java:/jdbc/acmeOrderDS] txSync=null]

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) *** the trackByTx state is false during enlist. ***org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:-1)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:467)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:599)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:467)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:139)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:56)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:161)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:182)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:159)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1859)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1836)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1816)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.doQuery(Loader.java:900)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:342)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:312)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.Loader.loadEntity(Loader.java:2121)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:82)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:72)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:65)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.loader.entity.LegacyBatchingEntityLoaderBuilder$LegacyBatchingEntityLoader.load(LegacyBatchingEntityLoaderBuilder.java:121)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3941)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:460)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:429)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:206)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:262)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:150)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1098)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.internal.SessionImpl.access$2000(SessionImpl.java:175)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2482)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.internal.SessionImpl.get(SessionImpl.java:994)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:807)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:781)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.jpa.container.AbstractEntityManager.find(AbstractEntityManager.java:193)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.ejb.orders.session.CustomerSession.getCustomer(CustomerSession.java:46)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.ejb.orders.session.CustomerSession.getInventories(CustomerSession.java:89)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) sun.reflect.GeneratedMethodAccessor69.invoke (Unknown Source)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) java.lang.reflect.Method.invoke(Method.java:606)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:259)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:398)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:242)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.ejb.orders.session.CustomerSessionLocal$$$view14.getInventories (Unknown Source)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.servlet.helper.AcmeAction.getHoldings(AcmeAction.java:277)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.servlet.helper.AcmeServletAction.doHome(AcmeServletAction.java:281)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.servlet.AcmeAppServlet.performTask(AcmeAppServlet.java:209)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) com.acme.acme.servlet.AcmeAppServlet.doGet(AcmeAppServlet.java:78)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) javax.servlet.http.HttpServlet.service(HttpServlet.java:734)

12:46:50,182 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) javax.servlet.http.HttpServlet.service(HttpServlet.java:847)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:295)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:149)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:145)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:336)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:653)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:920)

12:46:50,183 INFO  [stdout] (http-f19lite/192.168.0.3:8080-19) java.lang.Thread.run(Thread.java:744)

Regards,

Jeremy

Message was edited by: Jeremy Whiting - add zip compatible archive of server logs.

[jesper.pedersen]

setTrackByTx is set to true, once the ConnectionListener is associated with the transaction, and stored in TransactionSynchronizationRegistry. This ties the physical connection (ManagedConnection) to the transaction.

setTrackByTx is set to false, if there was an error on the connection listener, or when the connection listener is returned to the pool. It is false too, if there is no transaction too of course.

Do you have an overview of what happens within the transaction boundary in the TRACE above ?

[whitingjr]

During the transaction two tasks happen in the AcmeAction.getHoldings method. Initially a Customer entity is retrieved. Then for the Customer an number of Inventories entity objects using the CustomerSession ejb. The trace above is the second lease of the associated logical connection to retrieve Inventories.

[jesper.pedersen]

But those methods has @TransactionAttribute(TransactionAttributeType.SUPPORTS), and I don't see where the transaction is started higher up in the call stack.

[whitingjr]

You are right. There isn't a transaction started. I've been through more of the log files and the only situations when the stack is dumped during enlistment is when a Connection is used without an associated transaction. My oversight. The state being false in these situations is to be expected.

Thank you for investigating this Jesper.

[jesper.pedersen]

Maybe the transaction analyzer - https://github.com/jbosstm/transaction-analyser - can be enhanced in future versions to help in tracking down enlistment scenarios.