14 Replies Latest reply on May 22, 2009 8:43 AM by jhalliday

    XA Transactions and Jboss 4.2.3

    pedrosena

      Hi Guys,

      I'm new to XA transaction, but I believe that this is some kind of unexpected behavior.

      My scenario:

      I have a web application that has one database schema per user, plus a global schema that all users share.

      I'm having trouble trying to make operations in both schemas in the same method.

      I read from schema1 then I try to insert in schema2, the following exception is thrown when I try to insert in schema 2(after reading from 1)

      org.hibernate.exception.GenericJDBCException: Cannot open connection
       at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
      ...
      Caused by: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f5701ff:78e:49ada4b1:3 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f5701ff:78e:49ada4b1:3 status: ActionStatus.ABORT_ONLY >)
       at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
       at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:69)
       at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
       ... 94 more
      Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f5701ff:78e:49ada4b1:3 status: ActionStatus.ABORT_ONLY >
       at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:340)
       at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:394)
       at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:838)
       at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
       ... 96 more
      


      I tried a local-tx-datasource and a XA datasource, in both situations I got the same error.

      Am I missing something here?

      Thanks in advance,

      Pedro Sena

        • 1. Re: XA Transactions and Jboss 4.2.3
          pedrosena

          Some aditional info:

          1) My method is demarcated with Seam @Transactional annotation.
          2) The operation runs fine if I avoid the query in schema1 before my insert in schema2

          Regards

          • 2. Re: XA Transactions and Jboss 4.2.3
            ejb3workshop

            I am having a similar issue. My application makes use of 3 datasources going to the same database. One supporting XA and the other two no-tx-datasource.

             

            I am using Oracle 10g

             

             


            14:47:48,951 INFO [Server] JBoss (MX MicroKernel) [4.2.3.GA (build: SVNTag=JBoss_4_2_3_GA date=200807181439)] Started in 1m:4s:969ms
            14:48:03,342 WARN [PageNotFound] No mapping for [/diagnostics/spring/j_security_check] in DispatcherServlet with name 'abc'
            14:48:35,092 WARN [JDBCExceptionReporter] SQL Error: 0, SQLState: null
            14:48:35,092 ERROR [JDBCExceptionReporter] Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:cf6:4a155b48:d1 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7
            :cf6:4a155b48:d1 status: ActionStatus.ABORT_ONLY >)
            14:48:35,092 INFO [DefaultLoadEventListener] Error performing load command
            org.hibernate.exception.GenericJDBCException: Cannot open connection
            at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
            at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
            at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
            at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
            at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
            at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
            at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
            at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
            at org.hibernate.loader.Loader.doQuery(Loader.java:673)
            at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
            at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
            at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
            at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
            at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3044)
            at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
            at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
            at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
            at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:195)
            at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
            at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
            at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
            at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
            at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:174)
            at org.jboss.ejb3.entity.TransactionScopedEntityManager.find(TransactionScopedEntityManager.java:171)
            at
            • 3. Re: XA Transactions and Jboss 4.2.3
              jhalliday

              > Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:cf6:4a155b48:d1 status: ActionStatus.ABORT_ONLY >; -
              > ...
              > org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)

              Transactions that have been marked setRollbackOnly can't have new connections (i.e. resources) enlisted with them. If you want to keep working you need a fresh transaction.

              • 4. Re: XA Transactions and Jboss 4.2.3
                ejb3workshop

                But this should be a new transaction. It happens in an SLSB method on the first time I am using the Entity Manager to find and object reference to an EJB3 entity bean. The transaction is container managed.

                My guess would be some configuration on the datasource is not correct, but I followed the examples shipped with jboss to the letter.


                • 5. Re: XA Transactions and Jboss 4.2.3
                  jhalliday

                  So turn on debug logging for the transaction system and the logs should show where the tx is being started and where it's being set rollback only.

                  • 6. Re: XA Transactions and Jboss 4.2.3
                    ejb3workshop

                    Thanks for the suggestion. Which package do I need to add to the log4j configuration for this ?

                    Alex

                    • 7. Re: XA Transactions and Jboss 4.2.3
                      mmusgrov



                      If you prefer more targeted logging then there is a section in transaction service property file ( jbossts-properties.xml) called

                      You probably want FAC_ATOMIC_ACTION (there is a good explaination of how it works in the ProgrammersGuide.pdf guide that comes with the distribution).

                      • 8. Re: XA Transactions and Jboss 4.2.3
                        mmusgrov

                        Sorry the forums editor pruned my primary response - use

                        <category name="com.arjuna">


                        • 9. Re: XA Transactions and Jboss 4.2.3
                          mmusgrov

                          And let me try it a

                          third time:
                          
                          <category name="com.arjuna">
                          
                          


                          • 10. Re: XA Transactions and Jboss 4.2.3
                            ejb3workshop

                            Thanks for this. I tried to enable this and it produce a lot of output but nothing that pointed towards the issue. As the application works when I point the datasources to SQL Server I don't think it's a problem with transactions.

                             

                            What is really strange is that after restarting JBoss the first call to the EntityManager succeeds

                             

                            Query query = m_entityManager.createQuery("Select c from ConfigurationItem c");

                             

                            but later on, in a new transaction a call to ConfigurationItem item = m_entityManager.find(ConfigurationItem.class, name) fails.

                             

                            Below is the extra output after enabling logging on JTA and hibernate

                             

                             


                            12:31:05,901 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                            12:31:05,901 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                            12:31:05,917 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                            12:31:05,917 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                            12:31:05,933 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.begin
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 2 )
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::BasicAction()
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Begin() for action-id -3f57fdd7:c58:4a168be0:f5
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::actionInitialise() for action-id -3f57fdd7:c58:4a168be0:f5
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::ActionHierarchy(5)
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::add(-3f57fdd7:c58:4a168be0:f5, 1)
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action -3f57fdd7:c58:4a168be0:f5 adding Thread[http-127.0.0.1-8080-3,5,jboss]
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action -3f57fdd7:c58:4a168be0:f5 adding Thread[http-127.0.0.1-8080-3,5,jboss] result = true
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
                            12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::insert ( BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.RUNNING, 300 )
                            12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement::ReaperElement ( BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.RUNNING, 300 )
                            12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing expiry 1242992165948 to now 1242991865948
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-3,5,jboss] sleeping for 300000
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@1641f43 )
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,995 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
                            12:31:05,995 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3f57fdd7:c58:4a168be0:fb, 1)
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 27, 25, 1--3f57fdd7:c58:4a168be0:f5-3f57fdd7:c58:4a168be0:fa > )
                            12:31:05,995 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3f57fdd7:c58:4a168be0:fb
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                            12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,073 WARN [JDBCExceptionReporter] SQL Error: 0, SQLState: null
                            12:31:06,073 ERROR [JDBCExceptionReporter] Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7
                            :c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >)
                            12:31:06,073 INFO [DefaultLoadEventListener] Error performing load command
                            org.hibernate.exception.GenericJDBCException: Cannot open connection
                            at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
                            at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
                            at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
                            at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
                            at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
                            at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
                            at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
                            at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
                            at org.hibernate.loader.Loader.doQuery(Loader.java:673)
                            at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
                            at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
                            at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
                            at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
                            at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3044)
                            at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
                            at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
                            at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
                            at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:195)
                            at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
                            at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
                            at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
                            at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
                            at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:174)
                            at org.jboss.ejb3.entity.TransactionScopedEntityManager.find(TransactionScopedEntityManager.java:171)
                            at com.abc.backend.services.AdministratorBean.removeUnusedProperties(AdministratorBean.java:1232)
                            at com.abc.backend.services.AdministratorBean.setConfigurationProperties(AdministratorBean.java:1186)
                            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                            at java.lang.reflect.Method.invoke(Method.java:597)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
                            at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
                            at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
                            at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
                            at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.stateless.StatelessContainer.dynamicInvoke(StatelessContainer.java:304)
                            at org.jboss.ejb3.remoting.IsLocalInterceptor.invokeLocal(IsLocalInterceptor.java:81)
                            at org.jboss.ejb3.remoting.IsLocalInterceptor.invoke(IsLocalInterceptor.java:72)
                            at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                            at org.jboss.ejb3.stateless.StatelessRemoteProxy.invoke(StatelessRemoteProxy.java:107)
                            at $Proxy149.setConfigurationProperties(Unknown Source)
                            at com.abc.web.DiagnosticsController.editConfiguration(DiagnosticsController.java:379)
                            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                            at java.lang.reflect.Method.invoke(Method.java:597)
                            at org.springframework.web.servlet.mvc.multiaction.MultiActionController.invokeNamedMethod(MultiActionController.java:446)
                            at org.springframework.web.servlet.mvc.multiaction.MultiActionController.handleRequestInternal(MultiActionController.java:384)
                            at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
                            at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
                            at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:858)
                            at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:792)
                            at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:476)
                            at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:441)
                            at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
                            at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
                            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
                            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
                            at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
                            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
                            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
                            at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
                            at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
                            at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
                            at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:524)
                            at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
                            at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
                            at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
                            at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
                            at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
                            at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
                            at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
                            at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
                            at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
                            at java.lang.Thread.run(Thread.java:619)
                            Caused by: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57f
                            dd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >)
                            at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:95)
                            at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
                            at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
                            ... 87 more
                            Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >
                            at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:319)
                            at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:402)
                            at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:849)
                            at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:89)
                            ... 89 more
                            12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
                            12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
                            12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,198 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,198 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                            12:31:06,198 WARN [JDBCExceptionReporter] SQL Error: 0, SQLState: null
                            • 11. Re: XA Transactions and Jboss 4.2.3
                              ejb3workshop

                              Thanks for this. I tried to enable this and it produce a lot of output but nothing that pointed towards the issue. As the application works when I point the datasources to SQL Server I don't think it's a problem with transactions.

                               

                              What is really strange is that after restarting JBoss the first call to the EntityManager succeeds

                               

                              Query query = m_entityManager.createQuery("Select c from ConfigurationItem c");

                               

                              but later on, in a new transaction a call to ConfigurationItem item = m_entityManager.find(ConfigurationItem.class, name) fails.

                               

                              Below is the extra output after enabling logging on JTA and hibernate

                               

                               


                              12:31:05,901 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                              12:31:05,901 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                              12:31:05,917 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                              12:31:05,917 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                              12:31:05,933 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.begin
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 2 )
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::BasicAction()
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Begin() for action-id -3f57fdd7:c58:4a168be0:f5
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::actionInitialise() for action-id -3f57fdd7:c58:4a168be0:f5
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::ActionHierarchy(5)
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::add(-3f57fdd7:c58:4a168be0:f5, 1)
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action -3f57fdd7:c58:4a168be0:f5 adding Thread[http-127.0.0.1-8080-3,5,jboss]
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action -3f57fdd7:c58:4a168be0:f5 adding Thread[http-127.0.0.1-8080-3,5,jboss] result = true
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
                              12:31:05,933 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::insert ( BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.RUNNING, 300 )
                              12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement::ReaperElement ( BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.RUNNING, 300 )
                              12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::check ()
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_2] - TransactionReaper::check - comparing expiry 1242992165948 to now 1242991865948
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,948 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.internal.arjuna.coordinator.ReaperThread_1] - Thread Thread[Thread-3,5,jboss] sleeping for 300000
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,948 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,964 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,979 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@1641f43 )
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,995 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 1 )
                              12:31:05,995 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (-3f57fdd7:c58:4a168be0:fb, 1)
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] XAResourceRecord.XAResourceRecord ( < 131075, 27, 25, 1--3f57fdd7:c58:4a168be0:f5-3f57fdd7:c58:4a168be0:fa > )
                              12:31:05,995 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for -3f57fdd7:c58:4a168be0:fb
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
                              12:31:05,995 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:06,011 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,026 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,042 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.equals
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,073 WARN [JDBCExceptionReporter] SQL Error: 0, SQLState: null
                              12:31:06,073 ERROR [JDBCExceptionReporter] Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7
                              :c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >)
                              12:31:06,073 INFO [DefaultLoadEventListener] Error performing load command
                              org.hibernate.exception.GenericJDBCException: Cannot open connection
                              at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
                              at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
                              at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
                              at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
                              at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426)
                              at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
                              at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
                              at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
                              at org.hibernate.loader.Loader.doQuery(Loader.java:673)
                              at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
                              at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
                              at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
                              at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
                              at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3044)
                              at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
                              at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
                              at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
                              at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:195)
                              at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
                              at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
                              at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
                              at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
                              at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:174)
                              at org.jboss.ejb3.entity.TransactionScopedEntityManager.find(TransactionScopedEntityManager.java:171)
                              at com.abc.backend.services.AdministratorBean.removeUnusedProperties(AdministratorBean.java:1232)
                              at com.abc.backend.services.AdministratorBean.setConfigurationProperties(AdministratorBean.java:1186)
                              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                              at java.lang.reflect.Method.invoke(Method.java:597)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
                              at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
                              at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
                              at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
                              at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.stateless.StatelessContainer.dynamicInvoke(StatelessContainer.java:304)
                              at org.jboss.ejb3.remoting.IsLocalInterceptor.invokeLocal(IsLocalInterceptor.java:81)
                              at org.jboss.ejb3.remoting.IsLocalInterceptor.invoke(IsLocalInterceptor.java:72)
                              at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
                              at org.jboss.ejb3.stateless.StatelessRemoteProxy.invoke(StatelessRemoteProxy.java:107)
                              at $Proxy149.setConfigurationProperties(Unknown Source)
                              at com.abc.web.DiagnosticsController.editConfiguration(DiagnosticsController.java:379)
                              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                              at java.lang.reflect.Method.invoke(Method.java:597)
                              at org.springframework.web.servlet.mvc.multiaction.MultiActionController.invokeNamedMethod(MultiActionController.java:446)
                              at org.springframework.web.servlet.mvc.multiaction.MultiActionController.handleRequestInternal(MultiActionController.java:384)
                              at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
                              at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
                              at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:858)
                              at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:792)
                              at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:476)
                              at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:441)
                              at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
                              at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
                              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
                              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
                              at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
                              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
                              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
                              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
                              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
                              at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
                              at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:524)
                              at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
                              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
                              at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
                              at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
                              at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
                              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
                              at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
                              at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
                              at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
                              at java.lang.Thread.run(Thread.java:619)
                              Caused by: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57f
                              dd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >)
                              at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:95)
                              at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
                              at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
                              ... 87 more
                              Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdd7:c58:4a168be0:f5 status: ActionStatus.ABORT_ONLY >
                              at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:319)
                              at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:402)
                              at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:849)
                              at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:89)
                              ... 89 more
                              12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
                              12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
                              12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,198 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,198 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
                              12:31:06,198 WARN [JDBCExceptionReporter] SQL Error: 0, SQLState: null
                              • 12. Re: XA Transactions and Jboss 4.2.3
                                jhalliday

                                > 12:31:06,058 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly

                                It obviously did not sink in the first time, so I'll say it again:

                                Transactions that have been marked setRollbackOnly can't have new connections (i.e. resources) enlisted with them. If you want to keep working you need a fresh transaction.

                                • 13. Re: XA Transactions and Jboss 4.2.3
                                  ejb3workshop

                                  thanks for clarifying this for me once more. My problem is that I don't see why the first transaction was rolled back in the first place. There is not logging output or any exception being thrown / visible.

                                  • 14. Re: XA Transactions and Jboss 4.2.3
                                    jhalliday

                                    It was not rollled back, it was marked set rollback only. The transaction system does not consider that an error, so it's logged at DEBUG level. You either need to enable logging for the rest of the server to see what is calling setRollbackOnly, or grab the source and set a breakpoint on that method.